首页 » ORACLE 9i-23c, PostgreSQL/GaussDB, 系统相关 » How to trace DB processes system calls using Strace -k

How to trace DB processes system calls using Strace -k

当前数据库种类较多,像oracle等闭源数据库在诊断特殊疑难问题时需要分析内部C函数的call stack, 目前的oradebug short_stack或errorstack,linux系统中的pstack只是dump当前的调用, 还有现在的开源数据库虽然可以查看源代码,但是没法较方便的方法在运行的进程过程中持续跟进多个内部调用的call stack. 增加了故障分析的复杂性和诊断时间, 这里看到了一种使用strace跟踪的方法记录一下。

利用linux平台的strace工具持续跟踪进程的call stack. 需要配合libunwind 选项与显示格式化脚本。

# strace -k
strace: invalid option -- 'k'
Try 'strace -h' for more information.

默认情况下linux7 上的strace –k选项无法使用

#man strace 
-k          Print the execution stack trace of the traced processes after each system call (experimental).   This  option  is
                   available only if strace is built with libunwind.

但是从strace文档中可以发现需要启用libunwind选项

#  strace -V
strace -- version 4.12

#  yum install libunwind libunwind-devel

下载strace 源码

#tar -xvf strace-5.19.tar
#cd strace-5.19
# ./configure --with-libunwind
# make
# make install

$ strace -V
strace -- version 5.19
Copyright (c) 1991-2022 The strace developers <https://strace.io>.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Optional features enabled: stack-trace=libunwind m32-mpers mx32-mpers


$ man strace 
       -k
       --stack-traces
                   Print the execution stack trace of the traced processes after each system call.

strace -k选项已可使用,跟踪一下oracle的后台进程看一下效果

# strace -k -p 4449
strace: Process 4449 attached
getrusage(RUSAGE_THREAD, {ru_utime={tv_sec=0, tv_usec=20562}, ru_stime={tv_sec=0, tv_usec=11215}, ...}) = 0
 > /usr/lib64/libc-2.17.so(getrusage+0x7) [0xf4d77]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(slcpums+0xce) [0x1243beee]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ksugtcpums+0x13) [0x11c6f873]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(kews_timeout+0xba) [0x11f6b70a]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ksu_dispatch_tac+0x5cc) [0x11c75adc]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ktmmon+0x2e1) [0x1a956d1]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ktmSmonMain+0xd6) [0x1a94be6]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ksbrdp+0x463) [0x3646933]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(opirip+0x21d) [0x3a2a8cd]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(opidrv+0x245) [0x22d3265]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(sou2o+0xa5) [0x2d85685]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(opimai_real+0xad) [0x9a9f1d]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(ssthrdmain+0x1a1) [0x2d91821]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(main+0x100) [0x9a9e40]
 > /usr/lib64/libc-2.17.so(__libc_start_main+0xf5) [0x22545]
 > /u01/app/oracle/product/19.2.0/db_1/bin/oracle(_start+0x29) [0x9a9c69]

格式化一下call stack

# strace -k -e trace=desc -y -p 4449 2>&1 |
awk '/^ > /{gsub(/[()]/," ");sub(/+0x/,"()&");printf "<-"$3;next}
{sub(/[(].*/,"()");printf "\n\n"$0}'

mmap()<-mmap64()+0x3a<-sskgmrf_validaterange()+0x50<-skgmrf_alloc()+0x6d9<-ksmrf_init_alloc()+0xfd<-ksmarfg()+0x140<-kgh_invoke_alloc_cb()+0xa2<-kghgex()+0xa99+0x12f5<-kghgex()+0x251<-kghfnd()+0x182<-kghalo()+0x12f5<-kghgex()+0x251<-kghalf()+0x22a<-kggslInit()+0x5b<-kkqanjProcAnsiJoin()+0x32<-qksqbApplyToQbc()+0x349<)+0x21b<-opiSem()+0x10e3<-opiprs()+0x141<-kksParseChildCursor()+0x20f<-rpiswu2()+0x7d2<-kksLoadChild()+0x14a3<-kxsGetRuntimeLock()+0x7bf<-kksfbc()+0x46d1<-kkspr()+0x72<-opiosq0()+0x913<-opiall0()+0x1226<-opikpr()+0x253<-opiodr()+0x4b2<-rpidrus()+0xc6<-skgmstack()+0x41<-rpidru()+0x84<-rpiswu2()+0x21d<-kprball()+0x416<ce<-kkdlpRCOperation()+0x60<-kkdlpReadProps()+0xf<-kqrReadFromDB()+0x14a<-kqrpre2()+0xafd<-kqrpre1()+0x28<-kkdlpExecSqlCbk()+0x198<-kkdlpExecSql()+0x65<-kkdlpG<-kttdtsn2()+0x30<-ktstprimess()+0x114<-ktmmon()+0x35f6<-ktmSmonMain()+0xd6<-ksbrdp()+0x463<-opirip()+0x21d<-opidrv()+0x245<-sou2o()+0xa5<-opimai_real()+0xad<-+0x100<-__libc_start_main()+0xf5<-_start()+0x29

mmap()<-mmap64()+0x3a<-sskgmrf_validaterange()+0x50<-skgmrf_alloc()+0x6d9<-ksmrf_init_alloc()+0xfd<-ksmarfg()+0x140<-kgh_invoke_alloc_cb()+0xa2<-kghgex()+0xa99+0x12f5<-kghgex()+0x251<-kghfnd()+0x182<-kghalo()+0x12f5<-kghgex()+0x251<-kghfnd()+0x182<-kghalo()+0x12f5<-kghgex()+0x251<-kghfnd()+0x182<-kghprmalo()+0x1e7<-klloc()+0xe3<-kggfaAllocClear()+0xc9<-kghsupmm()+0x379<-kghssgai()+0x3a4<-kgghtInitH()+0xe2<-qksqbRegistryToTree()+0x5c<-qksqbWriteRegistryXML()+0x1fe<-qksxaBuiuildXml()+0x28d<-xplCompact()+0x811<-qknDoExplain_2()+0xd4<-qknTblExplain()+0x688<-xpluls()+0xb8<-xplGenXpl()+0x2aa<-qkadrv2Post()+0x4e9<-qkadrv2()+0x108<-opitck()+0x51<-rpiswu2()+0x7d2<-kksLoadChild()+0x1e3d<-kksSetBindType()+0x1122<-kkscsSearchChildList()+0x997<-kksfbc()+0x3c1f<-opiexe()+0xb2d<-opiall0()+0x553<-opi2<-rpidrus()+0xc6<-skgmstack()+0x41<-rpidru()+0x84<-rpiswu2()+0x21d<-kprball()+0x416<-kkdlpRCOperation()+0x145<-kkdlpReadProps()+0xf<-kqrReadFromDB()+0x14a<-kqx28<-kkdlpExecSqlCbk()+0x198<-kkdlpExecSql()+0x65<-kkdlpGet()+0x132<-kttdtsn()+0x7a<-kttdtsn2()+0x30<-ktstprimess()+0x114<-ktmmon()+0x35f6<-ktmSmonMain()+0xd6<0x21d<-opidrv()+0x245<-sou2o()+0xa5<-opimai_real()+0xad<-ssthrdmain()+0x1a1<-main()+0x100<-__libc_start_main()+0xf5<-_start()+0x29

mmap()<-mmap64()+0x3a<-sskgmrf_validaterange()+0x50<-skgmrf_alloc()+0x6d9<-ksmrf_init_alloc()+0xfd<-ksmarfg()+0x140<-kgh_invoke_alloc_cb()+0xa2<-kghgex()+0xa99+0x12f5<-kghgex()+0x251<-kghfnd()+0x182<-kghalo()+0x12f5<-kghgex()+0x251<-kghalf()+0x22a<-kdsirsf()+0xe1d<-kdsirs_fco()+0xe2<-qertbFetch()+0x3821<-opifch2()+0xpr()+0x253<-opiodr()+0x4b2<-rpidrus()+0xc6<-skgmstack()+0x41<-rpidru()+0x84<-rpiswu2()+0x21d<-kprball()+0x416<-kkdlpRCOperation()+0x145<-kkdlpReadProps()+0xf<-pre2()+0xafd<-kqrpre1()+0x28<-kkdlpExecSqlCbk()+0x198<-kkdlpExecSql()+0x65<-kkdlpGet()+0x132<-kttdtsn()+0x7a<-kttdtsn2()+0x30<-ktstprimess()+0x114<-ktmmon()+0xksbrdp()+0x463<-opirip()+0x21d<-opidrv()+0x245<-sou2o()+0xa5<-opimai_real()+0xad<-ssthrdmain()+0x1a1<-main()+0x100<-__libc_start_main()+0xf5<-_start()+0x29

基于当前的call stack格式可以方便的从orafun.info 网站查询call stack调用内容

同样适用于LINUX平台上的国产或开源数据库如opengauss, postgreSQL 数据库, 如果是跟踪Opengauss数据库。

# strace -k -e trace=desc -y -p 2115 2>&1|
> awk '/^ > /{gsub(/[()]/," ");sub(/+0x/,"()&");printf "<-"$3;next} > {sub(/[(].*/,"()");printf "\n\n"$0}'


strace: Process 2115 attached

poll()<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

poll()<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

--- SIGUSR2 {si_signo=SIGUSR2, si_code=SI_TKILL, si_pid=2115, si_uid=54323} ---<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

open()<-__open_nocancel()+0x24<-_Z21CheckSwitchoverSignalv()+0x25<-_Z14GetHaShmemModev()+0x3b2<-_Z16gs_signal_handlev()+0x400<-_Z16gs_signal_handlev()+0x6a0<-_L_unlock_18()+0x2c<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

open()<-__open_nocancel()+0x24<-_Z21CheckFinishRedoSignalv()+0x24<-_Z14GetHaShmemModev()+0x3de<-_Z16gs_signal_handlev()+0x400<-_Z16gs_signal_handlev()+0x6a0<-_L_unlock_18()+0x2c<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

open()<-__open_nocancel()+0x24<-_Z18CheckPromoteSignalv()+0x2d<-_Z14GetHaShmemModev()+0x3fc<-_Z16gs_signal_handlev()+0x400<-_Z16gs_signal_handlev()+0x6a0<-_L_unlock_18()+0x2c<-__poll_nocancel()+0x24<-_Z9comm_pollP6pollfdmi()+0x83<-_Z24initialize_worker_thread15knl_thread_roleP4PortPv()+0x3a3<-_Z14PostmasterMainiPPc()+0x25db<-main()+0x3ed<-__libc_start_main()+0xf5<-_start()+0x29

— enjoy —

打赏

对不起,这篇文章暂时关闭评论。