开发反应原来执行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等待事件处理:等您坐沙发呢!