[20220531]模擬inactive session等待事件.txt
[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"
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/267265/viewspace-2898083/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- [20220531]inactive session等待事件2.txtSession事件
- [20220531]驗證inactive session出現的問題.txtSession
- read by other session等待事件Session事件
- read by other session 等待事件分析Session事件
- 【TUNE_ORACLE】等待事件之IO等待“read by other session”Oracle事件Session
- [20191203]大量resmgrcpu quantum等待事件.txt事件
- [20191125]探究等待事件的本源.txt事件
- [20220518]enq FU - contention等待事件.txtENQ事件
- [20201117]解析cursor pin S等待事件.txt事件
- [20220531]測試quiz night.txtUI
- v$session - 你看到的event真的是session當前的等待事件麼?Session事件
- [20191126]探究等待事件的本源2.txt事件
- [20191127]探究等待事件的本源4.txt事件
- [20201204]關於等待事件Log File Sync.txt事件
- [20180918]等待事件SQL/Net more data from client.txt事件SQLclient
- [20180925]等待事件SQLNet more data from client 6.txt事件SQLclient
- [20180922]等待事件SQLNet more data from client 4.txt事件SQLclient
- [20180920]等待事件SQLNet more data from client 3.txt事件SQLclient
- [20180926]等待事件SQLNet more data from client 7.txt事件SQLclient
- [20211031]18c row cache mutext等待事件探究.txtMutex事件
- [20210315]理解db file parallel read等待事件3.txtParallel事件
- [20210315]理解db file parallel read等待事件4.txtParallel事件
- [20210207]使用gdb檢視等待事件11g.txt事件
- 通過session模擬登陸Session
- Solidity事件，等待事件Solid事件
- [20211229]再論19c latch free等待事件分析.txt事件
- 【TUNE_ORACLE】等待事件之等待事件類別Oracle事件
- ZooKeeper如何模擬會話失效(Session Expired)會話Session
- [20181123]模擬ora-01555.txt
- Selenium等待事件Waits事件AI
- [20181031]模擬網路問題.txt
- [20240827]分析為什麼出現library cache lock等待事件2.txt事件
- [20240828]分析為什麼出現library cache lock等待事件5.txt事件
- [20181031]模擬ora-01591錯誤.txt
- [20181122]模擬ORA-08103錯誤.txt
- log file sync等待事件事件
- ORACLE 常見等待事件Oracle事件
- latch等待事件彙總事件