Network Security Internet Technology Development Database Servers Mobile Phone Android Software Apple Software Computer Software News IT Information

In addition to Weibo, there is also WeChat

Please pay attention

WeChat public account

Shulou

Use Linux Strace to trace and debug Oracle program processes

2025-01-17 Update From: SLTechnology News&Howtos shulou NAV: SLTechnology News&Howtos > Database >

Share

Shulou(Shulou.com)06/01 Report--

The so-called operating system is the middle layer in which the application communicates with the server hardware. All the operations of the application are to communicate with the operating system. The operating system is responsible for translating all interactions into device languages for hardware interaction.

When debugging Oracle faults and working on kernel principles, we often need to know the actions and details of running in the background. Some failure scenarios, such as the program process hang resident, unable to log in and other problems, need operating system-level monitoring to check the location problem.

Oracle itself already provides many tools of this type, such as oradebug, various wait events, and trace methods. In addition, various types of operating systems provide a number of system-level tools to help us monitor. This article mainly introduces the typical use of strace tools in Linux environment, waiting for friends to check.

1. Environmental introduction

The author uses Red Hat Red Hat 6.5 for testing.

[root@XXX-Standby-Asm ~] # cat / etc/redhat-release

Red Hat Enterprise Linux Server release 6.5 (Santiago)

[root@XXX-Standby-Asm] # uname-a

Linux XXX-Standby-Asm 2.6.32-431.el6.x86_64 # 1 SMP Sun Nov 10 22:19:54 EST 2013 x86 "64 GNU/Linux

The corresponding Oracle version is 11.2.0.4.

[oracle@XXX-Standby-Asm ~] $sqlplus / nolog

SQL*Plus: Release 11.2.0.4.0 Production on Tue Jun 16 16:39:21 2015

Copyright (c) 1982, 2013, Oracle. All rights reserved.

SQL > conn / as sysdba

Connected.

SQL > select * from v$version

BANNER

Oracle Database 11g Enterprise Edition Release 11.2.0.4.0-64bit Production

PL/SQL Release 11.2.0.4.0-Production

CORE 11.2.0.4.0 Production

TNS for Linux: Version 11.2.0.4.0-Production

NLSRTL Version 11.2.0.4.0-Production

2. Strace command information

Using the-h argument, you can call out the syntax format and individual usage parameters of the strace command.

[oracle@XXX-Standby-Asm] $strace-h

Usage: strace [- dDffhiqrtttTvVxx] [- a column] [- e expr]... [- o file]

[- p pid]... [- s strsize] [- u username] [- E var=val]...

[command [arg...]]

Or: strace-c [- D] [- e expr]... [- O overhead] [- S sortby] [- E var=val].

[command [arg...]]

-c-- count time, calls, and errors for each syscall and report summary

-f-- follow forks,-ff-- with output into separate files

-F-- attempt to follow vforks,-h-- print help message

-I-- print instruction pointer at time of syscall

-Q-suppress messages about attaching, detaching, etc.

-r-print relative timestamp,-t-- absolute timestamp,-tt-- with usecs

-T-- print time spent in each syscall,-V-- print version

-v-- verbose mode: print unabbreviated argv, stat, termio [s], etc. Args

-x-print non-ascii strings in hex,-xx-- print all strings in hex

-a column-- alignment COLUMN for printing syscall results (default 40)

-e expr-- a qualifying expression: option= [!] all or option= [!] val1 [, val2].

Options: trace, abbrev, verbose, raw, signal, read, or write

-o file-- send trace output to FILE instead of stderr

-O overhead-- set overhead for tracing syscalls to OVERHEAD usecs

-p pid-- trace process with process id PID, may be repeated

-D-- run tracer process as a detached grandchild, not as parent

-s strsize-limit length of print strings to STRSIZE chars (default 32)

-S sortby-- sort syscall counts by: time, calls, name, nothing (default time)

-u username-- run command as username handling setuid and/or setgid

-E var=val-- put var=val in the environment for command

-E var-- remove var from the environment for command

Among the many parameters, the more commonly used ones are as follows:

The ü-t parameter: you can display the time when the operating system procedure is called. This is very important in diagnosis. if you find that a certain execution process is time-consuming, you can locate what the problem is.

ü-p parameter: strace can not only monitor from the start of the process, but also enter a running process to debug according to the process number of the operating system.

ü-o parameter: if the output needs to be saved as a file, specify the file name with the-o parameter

ü-e parameter: monitor expression. Provide trace, signal, read and write to reflect monitoring projects. The commonly used parameter is trace=file, which focuses on the operating system file access level.

Next, we will demonstrate the strace application through two typical application scenarios.

3. Start program monitoring

An important example of strace monitoring research is sqlplus, which is used by many predecessors to test the file form that tracks access to the sqlplus startup process. To start strace monitoring sqlplus, you can enter the sqlplus command directly after the strace command.

-- start command

[oracle@localhost] $strace-t-e trace=file sqlplus / nolog

14:21:14 execve ("/ u01/app/oracle/bin/sqlplus", ["sqlplus", "/ nolog"], [/ * 31 vars * /]) = 0-start the command

14:21:14 access ("/ etc/ld.so.preload", R_OK) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ u01/app/oracle/lib/tls/x86_64/libsqlplus.so", O_RDONLY) =-1 ENOENT (No such file or directory)

14:21:14 stat ("/ u01/app/oracle/lib/tls/x86_64", 0x7fff3076da50) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ u01/app/oracle/lib/tls/libsqlplus.so", O_RDONLY) =-1 ENOENT (No such file or directory)

14:21:14 stat ("/ u01/app/oracle/lib/tls", 0x7fff3076da50) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ u01/app/oracle/lib/x86_64/libsqlplus.so", O_RDONLY) =-1 ENOENT (No such file or directory)

14:21:14 stat ("/ u01/app/oracle/lib/x86_64", 0x7fff3076da50) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ u01/app/oracle/lib/libsqlplus.so", O_RDONLY) = 3

14:21:14 open ("/ u01/app/oracle/lib/libclntsh.so.11.1", O_RDONLY) = 3

14:21:14 open ("/ u01/app/oracle/lib/libnnz11.so", O_RDONLY) = 3

14:21:14 open ("/ u01/app/oracle/lib/libdl.so.2", O_RDONLY) =-1 ENOENT (No such file or directory)

(for reasons of space, there are omissions. )

14:21:14 access ("/ etc/tnsnav.ora", F_OK) =-1 ENOENT (No such file or directory)

14:21:14 access ("/ u01/app/oracle/network/admin/tnsnav.ora", F_OK) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ u01/app/oracle/oracore/zoneinfo", O_RDONLY | O_NONBLOCK | O_DIRECTORY | O_CLOEXEC) = 6

14:21:14 open ("/ u01/app/oracle/oracore/zoneinfo/timezlrg_1.dat", O_RDONLY) = 7

14:21:14 open ("/ u01/app/oracle/oracore/zoneinfo/timezlrg_2.dat", O_RDONLY) = 7

(read all kinds of time zone data. )

14:21:14 open ("/ u01/app/oracle/oracore/zoneinfo/timezone_14.dat", O_RDONLY) = 7

14:21:14 open ("/ u01/app/oracle/oracore/zoneinfo/timezlrg_14.dat", O_RDONLY) = 6

14:21:14 open ("/ usr/lib64/libnuma.so", O_RDONLY) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ usr/lib64/libnuma.so.1", O_RDONLY) = 6

14:21:14 open ("/ proc/self/status", O_RDONLY) = 6

14:21:14 open ("/ sys/devices/system/node", O_RDONLY | O_NONBLOCK | O_DIRECTORY | O_CLOEXEC) = 6

14:21:14 open ("/ sys/devices/system/node/node0/meminfo", O_RDONLY) = 7

14:21:14 open ("/ sys/devices/system/cpu", O_RDONLY | O_NONBLOCK | O_DIRECTORY | O_CLOEXEC) = 6

14:21:14 open ("/ proc/self/status", O_RDONLY) = 6

14:21:14 open ("/ proc/sys/kernel/shmmax", O_RDONLY) = 6

14:21:14 open ("/ proc/meminfo", O_RDONLY) = 6

14:21:14 open ("/ usr/lib64/libnuma.so", O_RDONLY) =-1 ENOENT (No such file or directory)

14:21:14 open ("/ etc/localtime", O_RDONLY) = 6

14:21:14 open ("/ u01/app/oracle/rdbms/mesg/ocius.msb", O_RDONLY) = 6

SQL*Plus: Release 11.2.0.4.0 Production on Fri Jun 12 14:21:14 2015

Copyright (c) 1982, 2013, Oracle. All rights reserved.

-- the file read after startup.

14:21:14 stat ("login.sql", 0x7fff3076c740) =-1 ENOENT (No such file or directory)

14:21:14 stat ("/ u01/app/oracle/sqlplus/admin/glogin.sql", {st_mode=S_IFREG | 0644, st_size=368,...}) = 0

14:21:14 access ("/ u01/app/oracle/sqlplus/admin/glogin.sql", F_OK) = 0

14:21:14 statfs ("/ u01/app/oracle/sqlplus/admin/glogin.sql", {favotype = "EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=174170552, f_bfree=147038320, f_bavail=138190973, f_files=44236800, f_ffree=44019067, fancifsidy = {1821877354,763674030}, f_namelen=255, f_frsize=4096}) = 0

14:21:14 open ("/ u01/app/oracle/sqlplus/admin/glogin.sql", O_RDONLY) = 7

If you are in the process of starting sqlplus, log in directly. Login actions are also included in the tracking process.

[oracle@localhost] $strace-t-e trace=file sqlplus / as sysdba

14:29:30 execve ("/ u01/app/oracle/bin/sqlplus", ["sqlplus", "/", "as", "sysdba"], [/ * 31 vars * /]) = 0

(the same length, slightly. )

SQL*Plus: Release 11.2.0.4.0 Production on Fri Jun 12 14:29:30 2015

Copyright (c) 1982, 2013, Oracle. All rights reserved.

-- difference part

14:29:30 open ("/ u01/app/oracle/dbs/cm_xxxdb.dat", O_RDONLY | O_DSYNC) =-1 ENOENT (No such file or directory)

14:29:30 getcwd ("/ home/oracle", 256) = 13

14:29:30 open ("/ proc/self/cmdline", O_RDONLY) = 7

14:29:30 open ("/ etc/nsswitch.conf", O_RDONLY) = 7

14:29:30 open ("/ u01/app/oracle/lib/libnss_files.so.2", O_RDONLY) =-1 ENOENT (No such file or directory)

14:29:30 open ("/ etc/ld.so.cache", O_RDONLY) = 7

14:29:30 open ("/ lib64/libnss_files.so.2", O_RDONLY) = 7

14:29:30 open ("/ etc/passwd", O_RDONLY | O_CLOEXEC) = 7

14:29:30 open ("/ u01/app/oracle/lib/libnque11.so", O_RDONLY) = 7

14:29:30 getcwd ("/ home/oracle", 256) = 13

14:29:30 open ("/ u01/app/oracle/nls/data/lx20369.nlb", O_RDONLY) = 7

14:29:30 open ("/ u01/app/oracle/nls/data/lx207d0.nlb", O_RDONLY) = 7

14:29:30 readlink ("/ proc/self/fd/0", "/ dev/pts/0", 254) = 10

14:29:30 open ("/ etc/passwd", O_RDONLY | O_CLOEXEC) = 7

14:29:30 open ("/ etc/host.conf", O_RDONLY) = 7

14:29:30 open ("/ etc/resolv.conf", O_RDONLY) = 7

14:29:30 open ("/ etc/hosts", O_RDONLY | O_CLOEXEC) = 7

14:29:30 open ("/ etc/hostid", O_RDONLY) =-1 ENOENT (No such file or directory)

14:29:30 open ("/ etc/hosts", O_RDONLY | O_CLOEXEC) = 7

14:29:30 open ("/ u01/app/oracle/rdbms/mesg/oraus.msb", O_RDONLY) = 7

Connected to:

Oracle Database 11g Enterprise Edition Release 11.2.0.4.0-64bit Production

With the Partitioning, OLAP, Data Mining and Real Application Testing options

14:29:30 stat ("login.sql", 0x7fff0a822b10) =-1 ENOENT (No such file or directory)

14:29:30 stat ("/ u01/app/oracle/sqlplus/admin/glogin.sql", {st_mode=S_IFREG | 0644, st_size=368,...}) = 0

14:29:30 access ("/ u01/app/oracle/sqlplus/admin/glogin.sql", F_OK) = 0

14:29:30 statfs ("/ u01/app/oracle/sqlplus/admin/glogin.sql", {favotype = "EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=174170552, f_bfree=147038317, f_bavail=138190970, f_files=44236800, f_ffree=44019066, fancifsidy = {1821877354,763674030}, f_namelen=255, f_frsize=4096}) = 0

14:29:30 open ("/ u01/app/oracle/sqlplus/admin/glogin.sql", O_RDONLY) = 7

4. Track the mode of execution process

In addition to the methods described above, strace can also directly track and monitor executing system processes. Let's take a look at strace's monitoring of the Oracle background CKPT process.

[oracle@XXX-Standby-Asm ~] $ps-ef | grep ckpt

Grid 15950 1 0 Jun05? 00:01:02 asm_ckpt_+ASM

Oracle 18608 17848 0 17:35 pts/0 00:00:00 grep ckpt

Oracle 21395 1 0 Jun08? 00:04:27 ora_ckpt_xxxstb

From the root point of view, track the background process of process number 21395.

[root@XXX-Standby-Asm] # strace-t-p 21395

Process 21395 attached-interrupt to quit

17:36:42 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608271

17:36:42 semtimedop (6062085, {16,-1, 0}}, 1, {1, 840000000}) =-1 EAGAIN (Resource temporarily unavailable)

17:36:44 getrusage (RUSAGE_SELF, {ru_utime= {125,100}, ru_stime= {142,730301},...}) = 0

17:36:44 getrusage (RUSAGE_SELF, {ru_utime= {125,100}, ru_stime= {142,730301},...}) = 0

17:36:44 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608455

17:36:44 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608455

17:36:44 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:44 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:44 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608455

17:36:44 semtimedop (6062085, {{16,-1,0}}, 1, {3,0}) =-1 EAGAIN (Resource temporarily unavailable)-three second difference

17:36:47 getrusage (RUSAGE_SELF, {ru_utime= {125,100}, ru_stime= {142,731301},...}) = 0

17:36:47 getrusage (RUSAGE_SELF, {ru_utime= {125,100}, ru_stime= {142,731301},...}) = 0

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608755

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608755

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 read (16, "MSA\ 0\ 2\ 0\ 10\ 0 P\ 0\ 0\ 0\ 0\ 0\ 0\ 0\ 20mm P\ r\ 0\ 0\ 0\ 0\ 0\ 200\ 330\ 266\ 177\ 177\ 0\ 0", 80) = 80

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608756

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608756

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608756

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608756

17:36:47 times ({tms_utime=12512, tms_stime=14273, tms_cutime=0, tms_cstime=0}) = 645608756

17:36:47 semtimedop (6062085, {16,-1, 0}}, 1, {3, 0} ^ C

Process 21395 detached

From the inside, we can see how ckpt behaves.

5. Conclusion

Strace is a very useful tool in Linux environment. Using this tool well, we can get closer to the kernel details and enrich our knowledge and ability.

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.

Views: 0

*The comments in the above article only represent the author's personal views and do not represent the views and positions of this website. If you have more insights, please feel free to contribute and share.

Share To

Database

Wechat

© 2024 shulou.com SLNews company. All rights reserved.

12
Report