开发反应原来执行2个小时的存储过程,今天执行了10个小时都还没有结束,要求分析原因。
1,查看正在执行执行过程的会话
查看正在执行的存储过程,需要使用到dba_kgllock与x$kglob,v$session视图,只通过v$session sql_id来定位正在执行的存储过程是不确定的。
SQL> @sess_kgl_object.sql
Enter value for inst_id:
Enter value for sid:
Enter value for owner:
Enter value for object_name: HUANGTINGZHONGHT
INST
SID SESS_SADDR KGLLKHDL EVENT KGLLKMOD KGLLKREQ KGLLKTYPE OWNER:OBJECT_NAME
--------------- ---------------- ---------------- ------------------------- -------- -------- ---------- ---------------------
1.892 07000003CE53CEA0 0700000396DF1A40 read by other session 1 0 Lock EOMS.HUANGTINGZHONGHT
read by other session 2 0 Pin EOMS.HUANGTINGZHONGHT
这里可以看到在节点1会话为892正在执行这个会话
2,查看会话的信息
2.1 查看会话的详细信息
SQL> @print_table.sql
Enter value for query_sql: select * from v$session where sid=892
SADDR : 07000003CE53CEA0
SID : 892
SERIAL# : 42259
AUDSID : 18812540
PADDR : 07000003CF3B6AA0
USER# : 43
USERNAME : HTZ1
COMMAND : 7
OWNERID : 2147483644
TADDR : 07000003BA83AD28
LOCKWAIT :
STATUS : ACTIVE
SERVER : DEDICATED
SCHEMA# : 43
SCHEMANAME : HTZ1
OSUSER : oracle
PROCESS : 459500
MACHINE : HTZ.PW1
TERMINAL : UNKNOWN
PROGRAM : oracle@HTZ.PW1 (J005)
TYPE : USER
SQL_ADDRESS : 070000030BDCB578
SQL_HASH_VALUE : 1443821121
SQL_ID : cr121bbb0xxx1
SQL_CHILD_NUMBER : 0
PREV_SQL_ADDR : 0700000384AD2CE8
PREV_HASH_VALUE : 551443034
PREV_SQL_ID : 1231tzchdwqkk
PREV_CHILD_NUMBER : 0
PLSQL_ENTRY_OBJECT_ID : 1396908
PLSQL_ENTRY_SUBPROGRAM_ID : 1
PLSQL_OBJECT_ID :
PLSQL_SUBPROGRAM_ID :
MODULE :
MODULE_HASH : 0
ACTION :
ACTION_HASH : 0
CLIENT_INFO :
FIXED_TABLE_SEQUENCE : 16495040
ROW_WAIT_OBJ# : 1169971
ROW_WAIT_FILE# : 174
ROW_WAIT_BLOCK# : 274559
ROW_WAIT_ROW# : 0
LOGON_TIME : 2014-10-09 01:57:48
LAST_CALL_ET : 115411
PDML_ENABLED : NO
FAILOVER_TYPE : NONE
FAILOVER_METHOD : NONE
FAILED_OVER : NO
RESOURCE_CONSUMER_GROUP :
PDML_STATUS : DISABLED
PDDL_STATUS : DISABLED
PQ_STATUS : DISABLED
CURRENT_QUEUE_DURATION : 0
CLIENT_IDENTIFIER :
BLOCKING_SESSION_STATUS : UNKNOWN
BLOCKING_INSTANCE :
BLOCKING_SESSION :
SEQ# : 12570
EVENT# : 67
EVENT : read by other session
P1TEXT : file#
P1 : 174
P1RAW : 00000000000000AE
P2TEXT : block#
P2 : 274559
P2RAW : 000000000004307F
P3TEXT : class#
P3 : 1
P3RAW : 0000000000000001
WAIT_CLASS_ID : 1740759767
WAIT_CLASS# : 8
WAIT_CLASS : User I/O
WAIT_TIME : 0
SECONDS_IN_WAIT : 112822
STATE : WAITING
SERVICE_NAME : SYS$USERS
SQL_TRACE : DISABLED
SQL_TRACE_WAITS : FALSE
SQL_TRACE_BINDS : FALSE
可以得到HTZ1用户正在执行cr121bbb0xxx1这条sql,正在等待read by other session,last_call_et远远大于SEQ#的值,所以怀疑会话一直在等待read by other session死了。
2.2 通过ASH查询会话的历史seq#的值
select session_id,seq#,wait_time from v$active_session_history where session_id=892 order by SAMPLE_TIME;
SESSION_ID SEQ# WAIT_TIME
---------- ---------- ----------
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
892 12570 0
通过ASH中的SEQ#可以确认,会话一直等待read by other session.
3 查询阻塞者
这里通过we这个脚本来查询数据库的等待事件
SQL> @we.sql
USERNMAE
LAST_CALL SESS_SERIAL ROW_WAIT
I EVENT SEQ# OSPID FILE#:OBJ#:BLOCK#:ROW#
-- ------------------------- ---------------------- -------------------------------------------
1 SQL*Net message from clie HTZ1:0:37254 887:51173:463866 79:5791639:8022:0
kksfbc child completion HTZ1:758441:45477 1027:20336:565778 31:1049059:194315:0
Streams AQ: waiting for m SYS:4:42529 1062:3:290870 3:31091:11972:0
db file sequential read HTZ1:136554:41682 1008:48636:447046 174:1169971:274559:0
SQL*Net message from clie HTZ1:0:24929 922:47522:405506 32:1049059:229799:0
PX Deq: Execute Reply SYS:0:48497 823:40081:307530 1006:-1:414731:0
PX Deq: Execution Msg SYS:0:4 795:30460:279154 0:-1:0:0
db file sequential read STAT:36282:6735 861:6087:545000 77:232752:493164:0
kksfbc child completion HTZ1:781784:31407 1065:22800:487926 107:1046915:95713:0
read by other session HTZ1:115605:12570 892:42259:459500 174:1169971:274559:0
db file sequential read HTZ1:7:62475 843:2364:607122 239:1388452:273613:0
2 db file sequential read HTZ1:1:1201 1022:33270:99132 206:1075194:117325:0
SQL*Net message from clie HTZ1:0:56610 1025:40965:434358 228:1076377:324554:0
SQL*Net message from clie HTZ1:1:2319 983:32863:483456 45:701370:3840:0
SQL*Net message from clie HTZ1:1:16639 1042:45749:131360 0:-1:0:0
SQL*Net more data from cl HTZ1:1:7 993:20195:237660 0:-1:0:0
SQL*Net message from clie HTZ1:0:21373 938:44952:471910 60:1324140:259727:0
log file sync HTZ1:0:50035 926:3825:467954 0:-1:0:0
PX Deq: reap credit SYS:1:20 910:64687:192958 0:-1:0:0
SQL*Net message from clie HTZ1:1:47225 927:63915:500646 240:466862:308718:0
这里我们查询到阻塞进程为1008这个进程
4,查看会话1008的信息
查询方法跟上面一样,下面只贴出了ASH中的信息
select session_id,seq# from v$active_session_history where session_id=1008 order by SAMPLE_TIME;
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
1008 41682
说明 1008这个会话已经读取的时候给HANG住了。
5,KILL会话
SQL> !ps -ef|grep 447046
oracle 471118 344342 0 10:12:59 pts/11 0:00 grep 447046
oracle 447046 1 0 Oct 08 - 0:44 oracleHTZ11 (LOCAL=NO)
SQL> !kill -9 447046
SQL> !ps -ef|grep 447046
oracle 525054 344342 0 10:13:13 pts/11 0:00 grep 447046
KILL 1008这个SESSION后,恢复正常。


一次特殊的read by other session等待事件处理:等您坐沙发呢!