Recently I was having issue in our test environment, users were complaining that database is not responding for any queries, it appears to be in hanged state.
After checking database for possible causes for performance issues, I found following:
SQL> select event,count(0) from v$session where username is not null and status='ACTIVE' group by event; event count(0) ----------------------- ----------- db file sequential read 1 library cache lock 4 cursor: pin S wait on X 25 SQL*Net message to client 1
Definitely something was wrong with the database. So firstly I concentrated on wait event library cache lock. I found some user was executing following DDL on one of the highly accessible table in the database:
SQL> @s1 Enter Session ID: 1409 ====================================================================================================== SID/Serial : 1409,39547 Module : TOAD 10.6.1.3 SQL_ID : d489wrxp66a0m Foreground : PID: 11016:1228 - Toad.exe Shadow : PID: 12339 - oracle@test4.test.com Terminal : XXGGG / UNKNOWN OS User : C_GGG on TEST4\C_GGG2-L Ora User : SADB Status Flags: ACTIVE DEDICATED USER Tran Active : 000000028CC470A0 Login Time : Thu 11:44:52 Last Call : Thu 11:48:59 - 199.7 min Lock/ Latch : NONE/ NONE Latch Spin : NONE Current SQL statement: ALTER TABLE sadb.audit_log DROP UNUSED COLUMNS CHECKPOINT 1000 Previous SQL statement: Session Waits: WAITING: db file sequential read Connect Info: : TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.3.0 - Production : Oracle Advanced Security: encryption service for Linux: Version 11.2.0.3.0 - Production : Oracle Advanced Security: crypto-checksumming service for Linux: Version 11.2.0.3.0 - Production Locks: TYPE=AE H: S R: NONE - ID1=282717 ID2=0 DML/DATA ENQ H: X R: NONE - AUDIT_LOG ====================================================================================================
So here I got culprit for wait event “library cache lock“. Killing this session would have resolved sessions waiting for this wait event.
But what causing cursor: pin S wait on X?
I searched on Google for possible causes of this wait event, I found lots of documentation each pointing to different possibilities.
Is same session with SID : 1409 was the culprit? After describing v$session view, I found very interesting column – ‘final_blocking_session’ – which is introduced in Oracle 11g.
SQL> select distinct blocking_session from v$session where event='cursor: pin S wait on X'; BLOCKING_SESSION ---------------- 1305 1520 SQL> select sql_id from v$session where sid in (1305,1520); SQL_ID ------------- 4vcd40bta41pb 0h4n33suqpqtv SQL> select distinct final_blocking_session from v$session where event='cursor: pin S wait on X'; FINAL_BLOCKING_SESSION ---------------------- 1409
So I found the culprit :-). After killing session with SID : 1409, issue got resolved.
After searching on Metalink I found very useful note:
Troubleshooting Database Contention With V$Wait_Chains (Doc ID 1428210.1)
In 11.2 you can add v$session.final_blocking_session to see the final blocker. The final blocker is the session/process at the top of the wait chain. This is the session/process that maybe causing the problem. Example of query with final_blocking_session info:
set pages 1000 set lines 120 set heading off column w_proc format a50 tru column instance format a20 tru column inst format a28 tru column wait_event format a50 tru column p1 format a16 tru column p2 format a16 tru column p3 format a15 tru column Seconds format a50 tru column sincelw format a50 tru column blocker_proc format a50 tru column fblocker_proc format a50 tru column waiters format a50 tru column chain_signature format a100 wra column blocker_chain format a100 wra SELECT * FROM (SELECT 'Current Process: '||osid W_PROC, 'SID '||i.instance_name INSTANCE, 'INST #: '||instance INST,'Blocking Process: '||decode(blocker_osid,null,'<none>',blocker_osid)|| ' from Instance '||blocker_instance BLOCKER_PROC, 'Number of waiters: '||num_waiters waiters, 'Final Blocking Process: '||decode(p.spid,null,'<none>', p.spid)||' from Instance '||s.final_blocking_instance FBLOCKER_PROC, 'Program: '||p.program image, 'Wait Event: ' ||wait_event_text wait_event, 'P1: '||wc.p1 p1, 'P2: '||wc.p2 p2, 'P3: '||wc.p3 p3, 'Seconds in Wait: '||in_wait_secs Seconds, 'Seconds Since Last Wait: '||time_since_last_wait_secs sincelw, 'Wait Chain: '||chain_id ||': '||chain_signature chain_signature, 'Blocking Wait Chain: '||decode(blocker_chain_id,null, '<none>',blocker_chain_id) blocker_chain FROM v$wait_chains wc, gv$session s, gv$session bs, gv$instance i, gv$process p WHERE wc.instance = i.instance_number (+) AND (wc.instance = s.inst_id (+) and wc.sid = s.sid (+) and wc.sess_serial# = s.serial# (+)) AND (s.final_blocking_instance = bs.inst_id (+) and s.final_blocking_session = bs.sid (+)) AND (bs.inst_id = p.inst_id (+) and bs.paddr = p.addr (+)) AND ( num_waiters > 0 OR ( blocker_osid IS NOT NULL AND in_wait_secs > 10 ) ) ORDER BY chain_id, num_waiters DESC) WHERE ROWNUM < 101;
This sql will give u OS process ID for final blocker.
Hope so u will find this post very useful 🙂
Cheers
Regards,
Adityanath
Categories: Peformance Tuning
Many thanks. It was great to find all this info. I am just missing the S1 script. Could you please share it?
Thank you so much for the great article. Can you share me s1 script?
Thanks for visiting and appreciate your feedback. 🙂
Please find below script contents:
—————————————————————————————————————————–
set serveroutput on size 50000
set echo off feed off veri off
accept SID prompt ‘Enter Session ID: ‘
DECLARE
v_pid number;
s sys.v_$session%ROWTYPE;
p sys.v_$process%ROWTYPE;
BEGIN
Begin
select spid into v_pid
from sys.v_$process p, sys.v_$session s
where p.addr = s.paddr
and (s.sid = &&SID)
;
exception
when no_data_found then
dbms_output.put_line(‘Unable to find process id &&SID!!!’);
return;
when others then
dbms_output.put_line(sqlerrm);
return;
end;
select * into p from sys.v_$process where spid = v_pid;
select * into s from sys.v_$session where paddr = p.addr;
dbms_output.put_line(‘=============================================================================================================’);
dbms_output.put_line(‘SID/Serial : ‘|| s.sid||’,’||s.serial#);
dbms_output.put_line(‘Module : ‘||s.module);
dbms_output.put_line(‘SQL_ID : ‘||s.sql_id);
dbms_output.put_line(‘Foreground : ‘|| ‘PID: ‘||s.process||’ – ‘||s.program);
dbms_output.put_line(‘Shadow : ‘|| ‘PID: ‘||p.spid||’ – ‘||p.program);
dbms_output.put_line(‘Terminal : ‘|| s.terminal || ‘/ ‘ || p.terminal);
dbms_output.put_line(‘OS User : ‘|| s.osuser||’ on ‘||s.machine);
dbms_output.put_line(‘Ora User : ‘|| s.username);
dbms_output.put_line(‘Status Flags: ‘|| s.status||’ ‘||s.server||’ ‘||s.type);
dbms_output.put_line(‘Tran Active : ‘|| nvl(s.taddr, ‘NONE’));
dbms_output.put_line(‘Login Time : ‘|| to_char(s.logon_time, ‘Dy HH24:MI:SS’));
dbms_output.put_line(‘Last Call : ‘|| to_char(sysdate-(s.last_call_et/60/60/24), ‘Dy HH24:MI:SS’) || ‘ – ‘ || to_char(s.last_call_et/60, ‘999990.0’) || ‘ min’);
dbms_output.put_line(‘Lock/ Latch : ‘|| nvl(s.lockwait, ‘NONE’)||’/ ‘||nvl(p.latchwait, ‘NONE’));
dbms_output.put_line(‘Latch Spin : ‘|| nvl(p.latchspin, ‘NONE’));
dbms_output.put_line(‘Current SQL statement:’);
for c1 in ( select * from sys.v_$sqltext
where HASH_VALUE = s.sql_hash_value order by piece) loop
dbms_output.put_line(chr(9)||c1.sql_text);
end loop;
dbms_output.put_line(‘Previous SQL statement:’);
for c1 in ( select * from sys.v_$sqltext
where HASH_VALUE = s.prev_hash_value order by piece) loop
dbms_output.put_line(chr(9)||c1.sql_text);
end loop;
dbms_output.put_line(‘Session Waits:’);
for c1 in ( select * from sys.v_$session_wait where sid = s.sid) loop
dbms_output.put_line(chr(9)||c1.state||’: ‘||c1.event);
end loop;
dbms_output.put_line(‘Connect Info:’);
for c1 in ( select * from sys.v_$session_connect_info where sid = s.sid) loop
dbms_output.put_line(chr(9)||’: ‘||c1.network_service_banner);
end loop;
dbms_output.put_line(‘Locks:’);
for c1 in ( select
decode(l.type,
— Long locks
‘TM’, ‘DML/DATA ENQ’, ‘TX’, ‘TRANSAC ENQ’,
‘UL’, ‘PLS USR LOCK’,
— Short locks
‘BL’, ‘BUF HASH TBL’, ‘CF’, ‘CONTROL FILE’,
‘CI’, ‘CROSS INST F’, ‘DF’, ‘DATA FILE ‘,
‘CU’, ‘CURSOR BIND ‘,
‘DL’, ‘DIRECT LOAD ‘, ‘DM’, ‘MOUNT/STRTUP’,
‘DR’, ‘RECO LOCK ‘, ‘DX’, ‘DISTRIB TRAN’,
‘FS’, ‘FILE SET ‘, ‘IN’, ‘INSTANCE NUM’,
‘FI’, ‘SGA OPN FILE’,
‘IR’, ‘INSTCE RECVR’, ‘IS’, ‘GET STATE ‘,
‘IV’, ‘LIBCACHE INV’, ‘KK’, ‘LOG SW KICK ‘,
‘LS’, ‘LOG SWITCH ‘,
‘MM’, ‘MOUNT DEF ‘, ‘MR’, ‘MEDIA RECVRY’,
‘PF’, ‘PWFILE ENQ ‘, ‘PR’, ‘PROCESS STRT’,
‘RT’, ‘REDO THREAD ‘, ‘SC’, ‘SCN ENQ ‘,
‘RW’, ‘ROW WAIT ‘,
‘SM’, ‘SMON LOCK ‘, ‘SN’, ‘SEQNO INSTCE’,
‘SQ’, ‘SEQNO ENQ ‘, ‘ST’, ‘SPACE TRANSC’,
‘SV’, ‘SEQNO VALUE ‘, ‘TA’, ‘GENERIC ENQ ‘,
‘TD’, ‘DLL ENQ ‘, ‘TE’, ‘EXTEND SEG ‘,
‘TS’, ‘TEMP SEGMENT’, ‘TT’, ‘TEMP TABLE ‘,
‘UN’, ‘USER NAME ‘, ‘WL’, ‘WRITE REDO ‘,
‘TYPE=’||l.type) type,
decode(l.lmode, 0, ‘NONE’, 1, ‘NULL’, 2, ‘RS’, 3, ‘RX’,
4, ‘S’, 5, ‘RSX’, 6, ‘X’,
to_char(l.lmode) ) lmode,
decode(l.request, 0, ‘NONE’, 1, ‘NULL’, 2, ‘RS’, 3, ‘RX’,
4, ‘S’, 5, ‘RSX’, 6, ‘X’,
to_char(l.request) ) lrequest,
decode(l.type, ‘MR’, o.object_name,
‘TD’, o.object_name,
‘TM’, o.object_name,
‘RW’, ‘FILE#=’||substr(l.id1,1,3)||
‘ BLOCK#=’||substr(l.id1,4,5)||’ ROW=’||l.id2,
‘TX’, ‘RS+SLOT#’||l.id1||’ WRP#’||l.id2,
‘WL’, ‘REDO LOG FILE#=’||l.id1,
‘RT’, ‘THREAD=’||l.id1,
‘TS’, decode(l.id2, 0, ‘ENQUEUE’, ‘NEW BLOCK ALLOCATION’),
‘ID1=’||l.id1||’ ID2=’||l.id2) objname
from sys.v_$lock l, dba_objects o
where sid = s.sid
and l.id1 = o.object_id(+) ) loop
dbms_output.put_line(chr(9)||c1.type||’ H: ‘||c1.lmode||’ R: ‘||c1.lrequest||’ – ‘||c1.objname);
end loop;
dbms_output.put_line(‘=============================================================================================================’);
END;
/
undef UNIXID
—————————————————————————————————————————–
Could you share us S1 script that will be really helpful for us
Thanks a lot…
You are Great Aditya…Thank you so much for your response…
Great Post Thanks Aditya
Thanks for visiting and appreciate your feedback. 🙂
Apprreciate the rеcommendation. Let me try it out.
Thanks for visiting and appreciate your feedback. 🙂
Thanks, info was very useful, I had a problem in production environment with pin S wait on X. Regards from México.
Thanks for visiting and appreciate your feedback.:-)
Interesting Article, I could co-relate to a similar issue I am facing now in my application. Thanks for the script
Thanks for visiting and appreciate your feedback.:-)
Regards,
Adi
Good day! This post could not be written any better!
Reading this post reminds me of my previous room mate!
He always kept talking about this. I will forward this page to him.
Pretty sure he will have a good read. Thanks for sharing!
Hello There,
Thanks for visiting and appreciate your feedback.:-)
Regards,
Adi
this site is my intake, really wonderful design and perfect content.
I visited a lot of website but I conceive this one holds something special in it in it
Thanks for this post, I am a big big fan of this internet site would like to go on updated.
whoah this blog is magnificent i love reading your articles. Keep up the great work! You know, lots of people are hunting around for this information, you can aid them greatly.
I am impressed with this site, real I am a fan.
I must thank you for the efforts you’ve put in penning this site. I am hoping to check out the same high-grade blog posts from you in the future as well. In truth, your creative writing abilities has inspired me to get my own, personal website now 😉
Hello there! I could have sworn I’ve been to this website before but after reading through some of the post I realized it’s new to me. Anyhow, I’m definitely happy I found it and I’ll be bookmarking and checking back often!
Fantastic goods from you, man. I have understand your stuff previous to and you are just extremely fantastic. I really like what you have acquired here, certainly like what you are stating and the way in which you say it. You make it entertaining and you still take care of to keep it smart. I cant wait to read far more from you. This is actually a terrific web site.
Having read this I believed it was extremely informative. I appreciate you finding the time and effort to put this short article together. I once again find myself personally spending a lot of time both reading and posting comments. But so what, it was still worth it!
I am extremely impressed together with your writing abilities as smartly with the layout for your weblog. Is this a paid subject matter or did you customize it yourself? Anyway stay up the excellent high quality writing, it’s rare to look a nice blog like this one nowadays.
Good day very nice site!! Man .. Beautiful .. Superb .. I’ll bookmark your website and take the feeds additionally…I’m satisfied to seek out a lot of useful info here in the post, we’d like develop more strategies on this regard, thank you for sharing.
Simply a smiling visitor here to share the love (:, btw great style and design .
I want reading through and I conceive this website got some really utilitarian stuff on it! .
Great post, you have pointed out some fantastic details , I too conceive this s a very fantastic website.
Keep all the articles coming. I love reading through your things. Cheers.