使用Procwatcher监控Oracle数据库锁定Contention(6)

日期：2020-06-07 栏目：程序人生浏览：次

7、结果分析——特定进程分析

Procwatcher脚本会将两类型进程进行针对性的dump过程：Oracle后台关键进程和特定锁定进程。在结果分析中发现的结果，对两个关键会话进行分析。

[oracle@SimpleLinux PRW_DB_ora11g]$ ls -l | egrep "1988|2012"

-rwxrwxrwx. 1 oracle oinstall 42192 Apr 30 09:46 prw_ora_fg_ora11g_1988_04-30-14.out

-rwxrwxrwx. 1 oracle oinstall 96874 Apr 30 09:46 prw_ora_fg_ora11g_2012_04-30-14.out

被阻塞进程2012的分析。

################################################################################

Procwatcher Debugging for Process 2012 ora_fg_ora11g

################################################################################

SQL: Wait Chains Report for Process 2012 ora_fg_ora11g

SQL> SQL> V WAITCHAINS (top 100 rows) Snapshot Taken At: Wed Apr 30 09:32:31 CST 2014

PROC 2012 : Current Process: 2012 SID: 42 SER#: 7 INST ora11g INST #: 1

PROC 2012 : Blocking Process: 1988 from Instance 1 Number of waiters: 0

PROC 2012 : Final Blocking Process: 1988 from Instance 1 Program: oracle@SimpleLinux.localdomain

PROC 2012 : Wait Event: enq: TX - row lock contention P1: 1415053318 P2: 655382 P3: 801

PROC 2012 : Seconds in Wait: 63 Seconds Since Last Wait:

PROC 2012 : Wait Chain: 1: 'SQL*Net message from client'<='enq: TX - row lock contention'

PROC 2012 : Blocking Wait Chain: <none>

################################################################################

SQL: Session Wait Report for Process 2012 ora_fg_ora11g

SQL> SQL> V SESSIONWAIT Snapshot Taken At: Wed Apr 30 09:32:34 CST 2014

PROC INST STATE EVENT P1 P2 P3 SEC

-------------------- --------------- ---------- ------------------------------ ---------- ---------- ---------- ----------

PROC 2012 INST ora11g WAITING enq: TX - row lock contention 1415053318 655382 801 68

################################################################################

SQL: Active Session History Report for Process 2012 ora_fg_ora11g

SQL> SQL> Snapshot Taken At: Wed Apr 30 09:32:45 CST 2014

PROC SAMPLE_TIME EVENT P1 P2 P3 WAIT_CLASS TIME_WAITED

-------------------- ------------------ ------------------------------ ---------- ---------- ---------- ------------ -----------

PROC 2012 30-APR-14 09.32.29 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.30 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.31 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.32 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.33 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.34 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.35 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.36 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.37 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.38 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.39 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.40 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.41 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.42 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.43 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.44 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.32.45 enq: TX - row lock contention 1415053318 655382 801 Application 0

################################################################################

SQL: Lock Report for Process 2012 ora_fg_ora11g

SQL> SQL> V LOCK Snapshot Taken At: Wed Apr 30 09:32:35 CST 2014

PROC PROC TY ID1 ID2 LMODE REQUEST BLOCK

-------------------- -------------------- -- ---------- ---------- ---------- ---------- ----------

PROC 2012 INST ora11g TX 655382 801 0 6 0

################################################################################

SQL: Current SQL Report for Process 2012 ora_fg_ora11g

SQL> SQL> Snapshot Taken At: Wed Apr 30 09:32:45 CST 2014

PROC 2012 - delete t

################################################################################

Wed Apr 30 09:33:11 CST 2014

F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD

0 S oracle 2012 1 0 80 0 - 136310 - 09:31 ? 00:00:00 oracleora11g (LOCAL=NO)

SQL*Plus: Release 11.2.0.4.0 Production on Wed Apr 30 09:33:12 2014

Enter user-name: SQL>Oracle pid: 37, Unix process pid: 2012, image: oracle@SimpleLinux.localdomain

Wed Apr 30 09:33:12 CST 2014

（篇幅原因，有省略……）

ksedsts()+265<-ksdxfstk()+19<-ksdxcb()+1719<-sspuser()+100<-semtimedop()+36<-sskgpwwait()+202<-skgpwwait()+138<-ksliwat()+1735<-kslwaitctx()+138<-ksqcmi()+3193<-ksqgtlctx()+3190<-ksqgelctx()+469<-ktuGetTxForXid()+95<-ktcwit1()+272<-kdddgb()+7397<-kdddel()+322<-kaudel()+77<-delrow()+1302<-qerdlFetch()+1512<-delexe()+841<-opiexe()+9487<-kpoal8()+1755<-opiodr()+962<-ttcpip()+1926<-opitsk()+1416<-opiino()+827<-opiodr()+962<-opidrv()+479<-sou2o()+80<-opimai_real()+109<-ssthrdmain()+220<-main()+147<-__libc_start_main()+230<-_start()+33

Statement processed.

/u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7486.trc

SQL> Disconnected from ORACLE

Cleaning up trc file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7486.trc

Cleaning up trm file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7486.trm

Average stack time: 0 seconds (rounded)

################################################################################

SQL: Wait Chains Report for Process 2012 ora_fg_ora11g

SQL> SQL> V WAITCHAINS (top 100 rows) Snapshot Taken At: Wed Apr 30 09:33:24 CST 2014

PROC 2012 : Current Process: 2012 SID: 42 SER#: 7 INST ora11g INST #: 1

PROC 2012 : Blocking Process: 1988 from Instance 1 Number of waiters: 0

PROC 2012 : Wait Chain: 1: 'SQL*Net message from client'<='enq: TX - row lock contention'

PROC 2012 : Blocking Wait Chain: <none>

################################################################################

SQL: Session Wait Report for Process 2012 ora_fg_ora11g

SQL> SQL> V SESSIONWAIT Snapshot Taken At: Wed Apr 30 09:33:29 CST 2014

PROC INST STATE EVENT P1 P2 P3 SEC

################################################################################

SQL: Active Session History Report for Process 2012 ora_fg_ora11g

SQL> SQL> Snapshot Taken At: Wed Apr 30 09:33:40 CST 2014

PROC SAMPLE_TIME EVENT P1 P2 P3 WAIT_CLASS TIME_WAITED

-------------------- ------------------ ------------------------------ ---------- ---------- ---------- ------------ -----------

PROC 2012 30-APR-14 09.33.23 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.24 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.25 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.26 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.27 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.28 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.29 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.30 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.31 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.32 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.33 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.34 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.35 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.36 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.37 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.38 enq: TX - row lock contention 1415053318 655382 801 Application 0

PROC 2012 30-APR-14 09.33.39 enq: TX - row lock contention 1415053318 655382 801 Application 0

################################################################################

SQL: Lock Report for Process 2012 ora_fg_ora11g

SQL> SQL> V LOCK Snapshot Taken At: Wed Apr 30 09:33:29 CST 2014

PROC PROC TY ID1 ID2 LMODE REQUEST BLOCK

-------------------- -------------------- -- ---------- ---------- ---------- ---------- ----------

PROC 2012 INST ora11g TX 655382 801 0 6 0

################################################################################

SQL: Current SQL Report for Process 2012 ora_fg_ora11g

SQL> SQL> Snapshot Taken At: Wed Apr 30 09:33:39 CST 2014

PROC 2012 - delete t

################################################################################

Wed Apr 30 09:34:02 CST 2014

F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD

0 S oracle 2012 1 0 80 0 - 136310 - 09:31 ? 00:00:00 oracleora11g (LOCAL=NO)

第二个会话1988信息导出。

################################################################################

Procwatcher Debugging for Process 1988 ora_fg_ora11g

################################################################################

SQL: Wait Chains Report for Process 1988 ora_fg_ora11g

SQL> SQL> V WAITCHAINS (top 100 rows) Snapshot Taken At: Wed Apr 30 09:32:31 CST 2014

PROC 1988 : Current Process: 1988 SID: 35 SER#: 45 INST ora11g INST #: 1

PROC 1988 : Blocking Process: <none> from Instance Number of waiters: 1

PROC 1988 : Final Blocking Process: <none> from Instance Program:

PROC 1988 : Wait Event: SQL*Net message from client P1: 1413697536 P2: 1 P3: 0

PROC 1988 : Seconds in Wait: 137 Seconds Since Last Wait:

PROC 1988 : Wait Chain: 1: 'SQL*Net message from client'<='enq: TX - row lock contention'

PROC 1988 : Blocking Wait Chain: <none>

################################################################################

SQL: Lock Report for Process 1988 ora_fg_ora11g

SQL> SQL> V LOCK Snapshot Taken At: Wed Apr 30 09:32:35 CST 2014

PROC PROC TY ID1 ID2 LMODE REQUEST BLOCK

-------------------- -------------------- -- ---------- ---------- ---------- ---------- ----------

PROC 1988 INST ora11g TX 655382 801 6 0 1

################################################################################

Wed Apr 30 09:33:09 CST 2014

F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD

0 S oracle 1988 1 0 80 0 - 137340 - 09:29 ? 00:00:00 oracleora11g (LOCAL=NO)

SQL*Plus: Release 11.2.0.4.0 Production on Wed Apr 30 09:33:11 2014

Enter user-name: SQL> Oracle pid: 33, Unix process pid: 1988, image: oracle@SimpleLinux.localdomain

Wed Apr 30 09:33:11 CST 2014

ksedsts()+265<-ksdxfstk()+19<-ksdxcb()+1719<-sspuser()+100<-read()+35<-nttfprd()+276<-nsbasic_brc()+333<-nsbrecv()+72<-nioqrc()+459<-opikndf2()+954<-opitsk()+642<-opiino()+827<-opiodr()+962<-opidrv()+479<-sou2o()+80<-opimai_real()+109<-ssthrdmain()+220<-main()+147<-__libc_start_main()+230<-_start()+33

Wed Apr 30 09:33:11 CST 2014

/u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7318.trc

SQL> Disconnected from ORACLE

Cleaning up trc file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7318.trc

Cleaning up trm file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_7318.trm

Average stack time: 1 seconds (rounded)

################################################################################

SQL: Wait Chains Report for Process 1988 ora_fg_ora11g

SQL> SQL> V WAITCHAINS (top 100 rows) Snapshot Taken At: Wed Apr 30 09:33:24 CST 2014

PROC 1988 : Current Process: 1988 SID: 35 SER#: 45 INST ora11g INST #: 1

PROC 1988 : Blocking Process: <none> from Instance Number of waiters: 1

PROC 1988 : Final Blocking Process: <none> from Instance Program:

PROC 1988 : Wait Event: SQL*Net message from client P1: 1413697536 P2: 1 P3: 0

PROC 1988 : Seconds in Wait: 191 Seconds Since Last Wait:

PROC 1988 : Wait Chain: 1: 'SQL*Net message from client'<='enq: TX - row lock contention'

PROC 1988 : Blocking Wait Chain: <none>

################################################################################

SQL: Lock Report for Process 1988 ora_fg_ora11g

SQL> SQL> V LOCK Snapshot Taken At: Wed Apr 30 09:33:29 CST 2014

PROC PROC TY ID1 ID2 LMODE REQUEST BLOCK

-------------------- -------------------- -- ---------- ---------- ---------- ---------- ----------

PROC 1988 INST ora11g TX 655382 801 6 0 1

################################################################################

Wed Apr 30 09:34:00 CST 2014

F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD

0 S oracle 1988 1 0 80 0 - 137340 - 09:29 ? 00:00:00 oracleora11g (LOCAL=NO)

SQL*Plus: Release 11.2.0.4.0 Production on Wed Apr 30 09:34:02 2014

Enter user-name: SQL> Oracle pid: 33, Unix process pid: 1988, image: oracle@SimpleLinux.localdomain

Wed Apr 30 09:34:02 CST 2014

/u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_12041.trc

SQL> Disconnected from ORACLE

Cleaning up trc file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_12041.trc

Cleaning up trm file /u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_12041.trm

Average stack time: 0 seconds (rounded)

8、结论

Procwatcher是Oracle官方提供的一个方便的脚本工具。笔者认为它解决了我们在诊断过程中常苦恼的几个问题。首先是平台操作命令接口统一。不同的操作系统，对于进程管理监控的命令方式是不同的。在现场复杂紧张的情况下，初学者进行快速操作是有一定的难度。而Procwatcher提供了统一方便的命令接口。其次是频度采样。Procwatcher可以针对不同的问题，对系统进程进行多次的诊断采样。最后是分析能力。当高并发的OLTP系统出现等待问题，快速检索出问题进程是一个挑战。而Procwatcher脚本提供的接口分析报告，可以快速协助我们解决进程定位问题。

转载注明出处：https://www.heiqu.com/8cf754c1597c8509f1cefe9ec07fec7b.html

使用Procwatcher监控Oracle数据库锁定Contention(6)

相关推荐