[20220531]模拟inactive session等待事件.txt

来源：这里教程网时间：2026-03-03 17:40:51 作者：

[20220531]模拟inactive session等待事件.txt --//上个星期做了生产系统inactive session等待事件的探究.猜测可能是防水墙审计一些应用无法登陆,通过job kill这些回话导致的情 --//况.有许多问题不是很理解,在测试环境模拟看看. 1.环境: SCOTT@book> @ ver1 PORT_STRING VERSION BANNER ------------------------------ -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production SYS@book> @ ev_name "inactive session" EVENT# EVENT_ID NAME PARAMETER1 PARAMETER2 PARAMETER3 WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------- ---------------------------------------- -------------------- -------------------- -------------------- ------------- ----------- --------------- 422 3757863830 inactive session session# waited instance|serial 1893977003 0 Other 2.建立测试脚本: $ cat ee1.txt --//select count(*) from emp,all_objects,all_objects; select /*+ test &&1 */ count(*) from emp,all_objects,all_objects; --//host sleep &1 quit --//注：采用host sleep &1测试不出来或者讲问题不能再现。我就不贴出测试host sleep &1的结果了. $ cat ee2.txt set head off feedback off select sid,serial# from v$session where username='SCOTT' and module='SQL*Plus'; set head on feedback on quit $ cat ee3.txt --//alter system kill session '&&1,&&2' ; alter system kill session '&&1,&&2' immediate; quit --//简单说明:使用ee1.txt 脚本启动多个回话. ee2.txt 脚本收集要kill session的sid,serial#. --//ee3.txt执行kill session. 注意测试存在两个方式没有immediate以及有immediate的情况. 3.测试1: --//先测试采用immediate kill session的情况。 --//同时启动10个回话. $ seq 10 | xargs -IQ -P 10 sqlplus -s -l scott/book @ee1.txt Q zzdate sqlplus -s -l / as sysdba @ ee2.txt | xargs -IQ -P 10 echo sqlplus -s -l / as sysdba @ee3.txt Q | bash zzdate SYS@book> @ wcy trunc(sysdate)+09/24+29/1440+17/86400 trunc(sysdate)+09/24+29/1440+48/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) no rows selected --//可以看出采用immediate kill session 不会出现inactive session 等待事件。 4.测试2： --//修改ee3.txt 脚本，不采用immediate参数。 $ cat ee3.txt alter system kill session '&&1,&&2' ; --//alter system kill session '&&1,&&2' immediate; quit --//同时启动10个回话.session 1： $ seq 10 | xargs -IQ -P 10 sqlplus -s -l scott/book @ee1.txt Q --//session 2： SYS@book> select sid,serial#,sql_id from v$session where username='SCOTT' and module='SQL*Plus'; SID SERIAL# SQL_ID ---------- ---------- ------------- 53 47 7zu90y1p0hgc5 70 15 1ntbg5gvxqpfd 104 9 11m3ncc7m3yx8 122 9 fa54u9k0r8dfn 138 9 4309m1zs0dt31 154 9 cqq7gtq45wxxj 172 7 apqywqcrmj20g 189 7 9wbujw07bx159 206 7 37b3pyat08r6m 223 7 d91dc8j7j5w99 10 rows selected. --//这样10个session执行的sql语句sql_id不同。 zzdate sqlplus -s -l / as sysdba @ ee2.txt | xargs -IQ echo sqlplus -s -l / as sysdba @ee3.txt Q | bash --//注意xargs 没有-P 10参数。 zzdate --//session 2： SYS@book> @ wcy trunc(sysdate)+09/24+37/1440+19/86400 trunc(sysdate)+09/24+37/1440+58/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN ------ ---------- ---------- ------ ------------------------------------------------------------------- ------------------- ------------------- 10% 1 0 1 -> 104,9,@1=>240,17,@1=>inactive session -> [idle blocker 1,104,9] 2022-05-31 09:37:44 2022-05-31 09:37:44 10% 1 0 1 -> 138,9,@1=>53,51,@1=>inactive session -> [idle blocker 1,138,9] 2022-05-31 09:37:46 2022-05-31 09:37:46 10% 1 0 1 -> 154,9,@1=>53,53,@1=>inactive session -> [idle blocker 1,154,9] 2022-05-31 09:37:47 2022-05-31 09:37:47 10% 1 0 1 -> 206,7,@1=>53,59,@1=>inactive session -> [idle blocker 1,206,7] 2022-05-31 09:37:50 2022-05-31 09:37:50 10% 1 0 1 -> ,,@=>53,61,@1=>inactive session 2022-05-31 09:37:51 2022-05-31 09:37:51 10% 1 0 1 -> ,,@=>53,55,@1=>inactive session 2022-05-31 09:37:48 2022-05-31 09:37:48 10% 1 0 1 -> ,,@=>240,13,@1=>inactive session 2022-05-31 09:37:42 2022-05-31 09:37:42 10% 1 0 1 -> ,,@=>53,49,@1=>inactive session 2022-05-31 09:37:45 2022-05-31 09:37:45 10% 1 0 1 -> 70,15,@1=>240,15,@1=>inactive session -> [idle blocker 1,70,15] 2022-05-31 09:37:43 2022-05-31 09:37:43 10% 1 0 1 -> 189,7,@1=>53,57,@1=>inactive session -> [idle blocker 1,189,7] 2022-05-31 09:37:49 2022-05-31 09:37:49 10 rows selected. SYS@book> @ashtop event,sid,serial "event='inactive session'" trunc(sysdate)+09/24+37/1440+19/86400 trunc(sysdate)+09/24+37/1440+58/86400 Total Distinct Distinct Seconds AAS %This EVENT SID SERIAL FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ---------------- ---- ---------- ------------------- ------------------- ---------- -------- 1 .0 10% | inactive session 53 49 2022-05-31 09:37:45 2022-05-31 09:37:45 1 1 1 .0 10% | inactive session 53 51 2022-05-31 09:37:46 2022-05-31 09:37:46 1 1 1 .0 10% | inactive session 53 53 2022-05-31 09:37:47 2022-05-31 09:37:47 1 1 1 .0 10% | inactive session 53 55 2022-05-31 09:37:48 2022-05-31 09:37:48 1 1 1 .0 10% | inactive session 53 57 2022-05-31 09:37:49 2022-05-31 09:37:49 1 1 1 .0 10% | inactive session 53 59 2022-05-31 09:37:50 2022-05-31 09:37:50 1 1 1 .0 10% | inactive session 53 61 2022-05-31 09:37:51 2022-05-31 09:37:51 1 1 1 .0 10% | inactive session 240 13 2022-05-31 09:37:42 2022-05-31 09:37:42 1 1 1 .0 10% | inactive session 240 15 2022-05-31 09:37:43 2022-05-31 09:37:43 1 1 1 .0 10% | inactive session 240 17 2022-05-31 09:37:44 2022-05-31 09:37:44 1 1 10 rows selected. --//sid=53,注意serial的变化+2.为什么会出现这样的变化。开始以为我没人登录了，仔细看前面的执行，实际上瞬间开启了10个kill session的进程。 --//注意xargs 我没有使用-p 参数，也就是在kill 会话不带immediate时影响了阻塞了后续登录。 sqlplus -s -l / as sysdba @ ee2.txt | xargs -IQ echo sqlplus -s -l / as sysdba @ee3.txt Q | bash --//注意看一个细节。出现sid=240 3行，FIRST_SEEN=2022-05-31 09:37:42最早出现，也是这一个会话kill sid=53,等3秒后sid=53可以重用，执行完成完成后不断退出。 --//这样出现SERIAL +2(sid=53)的情况，这样就可以很好的解析上面看到的情况。 --//也就是使用kill参数immediae时，如果有用户登录，会收到阻塞，出现inactive session 等待事件。 5.测试3： --//如果我顺序kill这些会话情况如何呢？修改ee3.txt脚本注解quit。 $ cat ee3.txt alter system kill session '&&1,&&2' ; --alter system kill session '&&1,&&2' immediate; --quit --//session 1: $ seq 10 | xargs -IQ -P 10 sqlplus -s -l scott/book @ee1.txt Q zzdate sqlplus -s -l / as sysdba @ ee2.txt | xargs -IQ echo @ee3.txt Q >| ee4.txt $ cat ee4.txt @ee3.txt 53 81 @ee3.txt 70 25 @ee3.txt 104 13 @ee3.txt 122 11 @ee3.txt 138 11 @ee3.txt 154 11 @ee3.txt 172 9 @ee3.txt 189 9 @ee3.txt 206 9 @ee3.txt 223 9 --//等ee4.txt执行后执行如下： zzdate --//session 2: SYS@book> @ee4.txt SYS@book> @ wcy trunc(sysdate)+09/24+54/1440+41/86400 trunc(sysdate)+09/24+55/1440+41/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN ------ ---------- ------- ------ -------------------------------------------------------------------- ------------------- ------------------- 30% 3 .1 1 -> ,,@=>87,25,@1=>inactive session 2022-05-31 09:55:27 2022-05-31 09:55:32 20% 2 .0 1 -> 104,13,@1=>87,25,@1=>inactive session -> [idle blocker 1,104,13] 2022-05-31 09:55:29 2022-05-31 09:55:31 20% 2 .0 1 -> 206,9,@1=>87,25,@1=>inactive session -> [idle blocker 1,206,9] 2022-05-31 09:55:35 2022-05-31 09:55:36 10% 1 .0 1 -> 122,11,@1=>87,25,@1=>inactive session -> [idle blocker 1,122,11] 2022-05-31 09:55:30 2022-05-31 09:55:30 10% 1 .0 1 -> 172,9,@1=>87,25,@1=>inactive session -> [idle blocker 1,172,9] 2022-05-31 09:55:33 2022-05-31 09:55:33 10% 1 .0 1 -> 189,9,@1=>87,25,@1=>inactive session -> [idle blocker 1,189,9] 2022-05-31 09:55:34 2022-05-31 09:55:34 6 rows selected. --//有点小小意外，我开始以为这样就不会出现inactive session等待事件，实际上还是出现。而sid=87正是session 2，我执行ee4.txt的会话。 SYS@book> @ spid SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50 ---------- ---------- ------------------------ --------- ------ ------- ---------- -------------------------------------------------- 87 25 47655 DEDICATED 47656 29 12 alter system kill session '87,25' immediate; SYS@book> @ashtop event,sid,serial,BLOCKING_SESSION,BLOCKING_SESSION_SERIAL# "event='inactive session'" trunc(sysdate)+09/24+54/1440+41/86400 trunc(sysdate)+09/24+55/1440+41/86400 Total Distinct Distinct Seconds AAS %This EVENT SID SERIAL BLOCKING_SESSION BLOCKING_SESSION_SERIAL# FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ---------------- --- ---------- ---------------- ------------------------ ------------------- ------------------- ---------- -------- 3 .1 30% | inactive session 87 25 2022-05-31 09:55:27 2022-05-31 09:55:32 1 3 2 .0 20% | inactive session 87 25 104 13 2022-05-31 09:55:29 2022-05-31 09:55:31 1 2 2 .0 20% | inactive session 87 25 206 9 2022-05-31 09:55:35 2022-05-31 09:55:36 1 2 1 .0 10% | inactive session 87 25 122 11 2022-05-31 09:55:30 2022-05-31 09:55:30 1 1 1 .0 10% | inactive session 87 25 172 9 2022-05-31 09:55:33 2022-05-31 09:55:33 1 1 1 .0 10% | inactive session 87 25 189 9 2022-05-31 09:55:34 2022-05-31 09:55:34 1 1 6 rows selected. $ cat ee4.txt @ee3.txt 53 81 @ee3.txt 70 25 @ee3.txt 104 13 @ee3.txt 122 11 @ee3.txt 138 11 @ee3.txt 154 11 @ee3.txt 172 9 @ee3.txt 189 9 @ee3.txt 206 9 @ee3.txt 223 9 --//3+2+2+1+1+1 = 10秒。 6.测试4： --//--//如果我顺序kill这些会话情况, 并且每次kill 后，sleep 1秒呢。 --//session 1: $ seq 10 | xargs -IQ -P 10 sqlplus -s -l scott/book @ee1.txt Q zzdate sqlplus -s -l / as sysdba @ ee2.txt | xargs -IQ echo -e "@ee3.txt Q \nhost sleep 1" >| ee4_1.txxt $ cat ee4_1.txt @ee3.txt 104 17 host sleep 1 @ee3.txt 122 13 host sleep 1 @ee3.txt 138 13 host sleep 1 @ee3.txt 154 13 host sleep 1 @ee3.txt 172 11 host sleep 1 @ee3.txt 189 11 host sleep 1 @ee3.txt 206 11 host sleep 1 @ee3.txt 223 11 host sleep 1 @ee3.txt 240 29 host sleep 1 @ee3.txt 257 61 host sleep 1 --//等ee4_1.txt执行后执行如下： zzdate --//session 2: SYS@book> @ ee4_1.txt SYS@book> @ wcy trunc(sysdate)+10/24+09/1440+05/86400 trunc(sysdate)+10/24+11/1440+19/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN ------ ---------- ------- ------ ------------------------------------------------------------------- ------------------- ------------------- 50% 5 .0 1 -> ,,@=>87,25,@1=>inactive session 2022-05-31 10:10:54 2022-05-31 10:11:12 20% 2 .0 1 -> 172,11,@1=>87,25,@1=>inactive session -> [idle blocker 1,172,11] 2022-05-31 10:11:02 2022-05-31 10:11:04 10% 1 .0 1 -> 206,11,@1=>87,25,@1=>inactive session -> [idle blocker 1,206,11] 2022-05-31 10:11:06 2022-05-31 10:11:06 10% 1 .0 1 -> 138,13,@1=>87,25,@1=>inactive session -> [idle blocker 1,138,13] 2022-05-31 10:10:58 2022-05-31 10:10:58 10% 1 .0 1 -> 240,29,@1=>87,25,@1=>inactive session -> [idle blocker 1,240,29] 2022-05-31 10:11:10 2022-05-31 10:11:10 --//sleep 2秒呢？重复测试，结果如下: SYS@book> @ wcy trunc(sysdate)+10/24+13/1440+57/86400 trunc(sysdate)+10/24+14/1440+52/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN ------ ---------- ------- ------ ---------------------------------- ------------------- ------------------- 100% 10 .2 1 -> ,,@=>87,25,@1=>inactive session 2022-05-31 10:14:12 2022-05-31 10:14:39 SYS@book> @ashtop event,sid,serial,BLOCKING_SESSION,BLOCKING_SESSION_SERIAL# "event='inactive session'" trunc(sysdate)+10/24+13/1440+57/86400 trunc(sysdate)+10/24+14/1440+52/86400 Total Distinct Distinct Seconds AAS %This EVENT SID SERIAL BLOCKING_SESSION BLOCKING_SESSION_SERIAL# FIRST_SEEN LAST_SEEN Execs Seen Tstamps --------- ------- ------- ---------------- --- ---------- ---------------- ------------------------ ------------------- ------------------- ---------- -------- 10 .2 100% | inactive session 87 25 2022-05-31 10:14:12 2022-05-31 10:14:39 1 10 --//这样就不存在阻塞了。但是可以看出每次kill 一个会话就出现1次inactive session等待事件。应该是每次等待1秒。 --//补充我还测试了sleep 1.9秒的情况： SYS@book> @ wcy trunc(sysdate)+10/24+22/1440+47/86400 trunc(sysdate)+10/24+24/1440+57/86400 "event='inactive session'" -- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com ) %This SECONDS AAS #Blkrs WAIT_CHAIN FIRST_SEEN LAST_SEEN ------ ---------- ------- ------ ------------------------------------------------------------------ ------------------- ------------------- 90% 9 .1 1 -> ,,@=>87,25,@1=>inactive session 2022-05-31 10:24:05 2022-05-31 10:24:31 10% 1 .0 1 -> 70,47,@1=>87,25,@1=>inactive session -> [idle blocker 1,70,47] 2022-05-31 10:24:07 2022-05-31 10:24:07 7.附上测试脚本： $ alias zzdate alias zzdate='date +"trunc(sysdate)+%H/24+%M/1440+%S/86400 == %Y/%m/%d %T == timestamp'\''%Y-%m-%d %T'\''"' --//wcy.sql 脚本利用tpt的ash_wait_chains.sql脚本。 $ cat wcy.sql @ tpt/ash/ash_wait_chains BLOCKING_SESSION||','||BLOCKING_SESSION_SERIAL#||',@'||BLOCKING_INST_ID||'=>'||session_id||','||SESSION_SERIAL#||',@'||inst_id||'=>'||event "&&3" "&&1" "&&2"