dbaSQL
asked on
Oracle -- identify blocking session
In SQL Server I can capture details about blocking events with the Profiler trace. Is there any way to do the same within Oracle? Possibly a trigger based capture? I don't want anything after the fact. I need something that will help me identify the cause of the blocking. I have a blocking session that is happening every day at the same time again and again. I have a statement that potentially could capture the details, but I can never run it at exactly the right time. Isn't there a way to collect this? Somehow log the event that is causing the blocking every day?
SELECT vh.sid locking_sid,
vs.status status,
vs.program program_holding,
vw.sid waiter_sid,
vsw.program program_waiting
FROM v$lock vh,
v$lock vw,
v$session vs,
v$session vsw
WHERE (vh.id1, vh.id2) IN (SELECT id1, id2
FROM v$lock
WHERE request = 0
INTERSECT
SELECT id1, id2
FROM v$lock
WHERE lmode = 0)
AND vh.id1 = vw.id1
AND vh.id2 = vw.id2
AND vh.request = 0
AND vw.lmode = 0
AND vh.sid = vs.sid
AND vw.sid = vsw.sid;
SELECT vh.sid locking_sid,
vs.status status,
vs.program program_holding,
vw.sid waiter_sid,
vsw.program program_waiting
FROM v$lock vh,
v$lock vw,
v$session vs,
v$session vsw
WHERE (vh.id1, vh.id2) IN (SELECT id1, id2
FROM v$lock
WHERE request = 0
INTERSECT
SELECT id1, id2
FROM v$lock
WHERE lmode = 0)
AND vh.id1 = vw.id1
AND vh.id2 = vw.id2
AND vh.request = 0
AND vw.lmode = 0
AND vh.sid = vs.sid
AND vw.sid = vsw.sid;
well, if you know which session/program/machine it's running from
start a trace
http://www.orafaq.com/wiki/SQL_Trace
then tkprof the output and sort by longest time
don't aggregate if you are looking for a specific query execution
http://www.orafaq.com/wiki/TKProf
start a trace
http://www.orafaq.com/wiki/SQL_Trace
then tkprof the output and sort by longest time
don't aggregate if you are looking for a specific query execution
http://www.orafaq.com/wiki/TKProf
ASKER
>>add a time range to the where clause to narrow it down to the period in which you're interested
sdstuber, are you saying that I can go backwards in time, finding details regarding blocks that have already occurred?
sdstuber, are you saying that I can go backwards in time, finding details regarding blocks that have already occurred?
yes, IF you are licensed to use the v$active_session_history - (the diagnostic pack) then yes
ASH data is collected every second
http://docs.oracle.com/cd/E11882_01/server.112/e40402/dynviews_1007.htm#REFRN30299
it's not kept forever, but you can generally go back at least a few hours if not a day or two.
ASH data is collected every second
http://docs.oracle.com/cd/E11882_01/server.112/e40402/dynviews_1007.htm#REFRN30299
it's not kept forever, but you can generally go back at least a few hours if not a day or two.
ASKER
Hi sdstuber. I ran this statement at first, but it ran for days before I killed it with CTRL + C:
select * from v$active_session_history where blocking_session is not null
So then I added this; and sample_time > SYSDATE - 2
I did that because I know the blocking occurred a couple times yesterday and the day before, and I thought this would help me narrow my focus to the past two days.
It still ran for an awful long time, but it did complete. My problem now is that I'm not real sure if I even got anything. The file that I output has a whole bunch of what I've included in the attached, presumably for X number of sample_id values. But it looks like a bunch of headers to me, without any data. Hopefully I am misreading this. Can you clarify, sd?
blocking_history_output.txt
select * from v$active_session_history where blocking_session is not null
So then I added this; and sample_time > SYSDATE - 2
I did that because I know the blocking occurred a couple times yesterday and the day before, and I thought this would help me narrow my focus to the past two days.
It still ran for an awful long time, but it did complete. My problem now is that I'm not real sure if I even got anything. The file that I output has a whole bunch of what I've included in the attached, presumably for X number of sample_id values. But it looks like a bunch of headers to me, without any data. Hopefully I am misreading this. Can you clarify, sd?
blocking_history_output.txt
you didn't capture the output and it's wrapped so as to be mostly unreadable.
based on the output, it looks like you're using sqlplus, so set the linesize wide enough to support all of the columns, or select fewer columns.
you probably don't need all of them. Use the doc link above to decide which columns you might find useful.
Instead of putting in a wide range, put in a date/time range that applies to the time you're interested in.
ASH captures a lot of data, add any other filters that apply.
Do you know the sql_id or the blocked session? Do you know the machine, the user, etc? If so, just as you would with any other sql query, add them to the where clause so you can exclude irrelevant data.
Don't make your search harder than it needs to be, it's just a sql statement.
based on the output, it looks like you're using sqlplus, so set the linesize wide enough to support all of the columns, or select fewer columns.
you probably don't need all of them. Use the doc link above to decide which columns you might find useful.
Instead of putting in a wide range, put in a date/time range that applies to the time you're interested in.
ASH captures a lot of data, add any other filters that apply.
Do you know the sql_id or the blocked session? Do you know the machine, the user, etc? If so, just as you would with any other sql query, add them to the where clause so you can exclude irrelevant data.
Don't make your search harder than it needs to be, it's just a sql statement.
ASKER
Yes, I know the sid. It's always sid 575. The last one I got was 6:26PM servertime, this evening --
Message=Session 575 is blocking 4 other sessions
Yes, I am using sqlplus. I will try to clean up this output.
Message=Session 575 is blocking 4 other sessions
Yes, I am using sqlplus. I will try to clean up this output.
well, if you know the blocking sid already, then blocking_session is not null is way over kill.
blocking_session=575 is what you're looking for.
But, if you know that already, then what is thread for? You asked for how to find the blocking session, but if you already know it, why ask?
blocking_session=575 is what you're looking for.
But, if you know that already, then what is thread for? You asked for how to find the blocking session, but if you already know it, why ask?
ASKER
>>But, if you know that already, then what is thread for? You asked for how to find the blocking session, but if you already know it, why ask?
I know the sid, but I don't know what it belongs to. I don't know what is causing the blocking.
I know the sid, but I don't know what it belongs to. I don't know what is causing the blocking.
that's a different question
but, you can look at the sql_id that is executing in the ash history too.
instead of looking at the blocking_session, look for session_id = 575. Find, look in v$sql for whatever sql_id it was executing while it was blocking.
if it's not there, then you'll need to go into history
select * from dba_hist_sqltext where sql_id = ....
but, you can look at the sql_id that is executing in the ash history too.
instead of looking at the blocking_session, look for session_id = 575. Find, look in v$sql for whatever sql_id it was executing while it was blocking.
if it's not there, then you'll need to go into history
select * from dba_hist_sqltext where sql_id = ....
ASKER
I cut the linesize down to 800 and ran it specifically on 575. Quickly glancing at the link you provided, these are the columns I chose:
sample_id,session_id,sessi on_state,s ql_opname, sql_exec_s tart,block ing_sessio n_status,b locking_se ssion,prog ram,machin e
My file is MUCH easier to read. The content still not 100% clear, but the output is much more intuitive. The sql_opname is blank but the program is runbatch.exe for every single one of hte logged blocked sessions. I am still very minimal in my handson with oracle, but this suggests to me that somebody is running something at the same time each day, and this is the source of the blocking. whatever is in that runbatch.exe. hope like hell tha isn't embarrassingly wrong translation.
what would you say, sd? Are there any other columns that you think I should include in the output?
sample_id,session_id,sessi
My file is MUCH easier to read. The content still not 100% clear, but the output is much more intuitive. The sql_opname is blank but the program is runbatch.exe for every single one of hte logged blocked sessions. I am still very minimal in my handson with oracle, but this suggests to me that somebody is running something at the same time each day, and this is the source of the blocking. whatever is in that runbatch.exe. hope like hell tha isn't embarrassingly wrong translation.
what would you say, sd? Are there any other columns that you think I should include in the output?
sql_id, then use that to query v$sql or dba_hist_sqltext to find the syntax for that sql
other options - plsql_object_id and plsql_subprogram_id use those to query dba_objects, If these columns are null, then the statement isn't coming from a pl/sql procedure/function/package . If it is, then you can find it.
other options - plsql_object_id and plsql_subprogram_id use those to query dba_objects, If these columns are null, then the statement isn't coming from a pl/sql procedure/function/package
ASKER
This is the new statement:
SELECT sample_id,session_id,sessi on_state,s ql_id,sql_ opname,sql _exec_star t,blocking _session_s tatus,bloc king_sessi on,program ,machine from v$active_session_history where blocking_session = 575 and sample_time > '20-NOV-16';
But my sql_id is coming back blank, along with sql_opname and sql_exec. Please tell me what I have misunderstood, sd.
blocking_details.txt
SELECT sample_id,session_id,sessi
But my sql_id is coming back blank, along with sql_opname and sql_exec. Please tell me what I have misunderstood, sd.
blocking_details.txt
ASKER
correction. this is the current statement, you can see I am no longer looking at 575 as the blocking session. it is the sessionid:
SELECT sample_id,session_id,sessi on_state,s ql_id,sql_ opname,sql _exec_star t,blocking _session_s tatus,bloc king_sessi on,program ,machine from v$active_session_history where session_id = 575 and sample_time > '20-NOV-16';
SELECT sample_id,session_id,sessi
ASKER CERTIFIED SOLUTION
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
ASKER
So the logwriter is the source of the recurring blocking? Am I understanding you correctly?
you tell me - you said that session was the blocker.
if you have identified the correct session, then yes, that session is the log writer process.
if you have identified the correct session, then yes, that session is the log writer process.
ASKER
The message I get every day is on 575, where it is blocking X number of other sessions, like this:
Message=Session 575 is blocking 2 other sessionst
If 575 is blocking other sessions, then it is not completely clear to me why we are looking for it as the session_id, rather than the blocking_session.
Message=Session 575 is blocking 2 other sessionst
If 575 is blocking other sessions, then it is not completely clear to me why we are looking for it as the session_id, rather than the blocking_session.
you changed the question.
when you started you wanted to know how to find the session that was causing a block.
therefore you look at blocking_session - because as the name says, it's the session that is blocking.
but, you changed the question because you already knew the session causing the block.
so, you look for the session_id, because that's the id of the session you already know (575)
read the documentation link above, it describes every column
when you started you wanted to know how to find the session that was causing a block.
therefore you look at blocking_session - because as the name says, it's the session that is blocking.
but, you changed the question because you already knew the session causing the block.
so, you look for the session_id, because that's the id of the session you already know (575)
read the documentation link above, it describes every column
ASKER
>>>I need something that will help me identify the cause of the blocking. I have a blocking session that is happening every day at the same time again and again.
I think I just voiced myself poorly. My goal has always been to identify the cause of the blocking. I should have been more clear, an said that I know the session id that is doing the blocking every day. I just don't know why it is happening, and I am trying to find the source of the blocking.
Because I know the session id for the blocking session is 575, why am I not using that in the statement as blocking_session, rather than session_id ? I apologize, sd, but that is the part that is still not clear.
I think I just voiced myself poorly. My goal has always been to identify the cause of the blocking. I should have been more clear, an said that I know the session id that is doing the blocking every day. I just don't know why it is happening, and I am trying to find the source of the blocking.
Because I know the session id for the blocking session is 575, why am I not using that in the statement as blocking_session, rather than session_id ? I apologize, sd, but that is the part that is still not clear.
>>> why am I not using that in the statement as blocking_session,
because that's not what blocking_session means. - that column indicates the session that is blocking the session identified by that row.
so
session_id blocking_session
1 2
would mean 1 is being blocked by 2
so,
select * from v$active_session_history where blocking_session = 575
means find sessions blocked by 575 - you don't care about this result
select * from v$active_session_history where session_id = 575
means find session 575 and see what it is. - this is what you are asking for now and you have your answer, it's log writer.
talk to your dba and your app team to alleviate log waits
because that's not what blocking_session means. - that column indicates the session that is blocking the session identified by that row.
so
session_id blocking_session
1 2
would mean 1 is being blocked by 2
so,
select * from v$active_session_history where blocking_session = 575
means find sessions blocked by 575 - you don't care about this result
select * from v$active_session_history where session_id = 575
means find session 575 and see what it is. - this is what you are asking for now and you have your answer, it's log writer.
talk to your dba and your app team to alleviate log waits
ASKER
I may have it. We know the session id due to what is returned in the blocking warnings. The statement that I am calling is just going into the session history for that id. And, the sql_id is null in the output because it is not an application or client piece, it is the server itself. Specifically, the logwriter.
Yes?
Yes?
yes
ASKER
Thank you for the assistance, sd. The guidance you've provided was tremendous. Hugely appreciate you taking the time to help me work through this.
SELECT inst_id,
sid,
username,
sql_id,
row_wait_obj#,
row_wait_file#,
row_wait_block#,
row_wait_row#,
blocking_session_status,
blocking_instance,
blocking_session
FROM gv$session
WHERE blocking_session IS NOT NULL;
if you are not using RAC, you can use v$session instead and remove the inst_id and blocking_instance columns from the query
You say you don't want anything after the fact, why not? If you're licensed to use ASH data, that makes it very easy as long as the blocking lasts for a few seconds or more.
select * from v$active_session_history where blocking_session is not null
add a time range to the where clause to narrow it down to the period in which you're interested
if you're not licensed then set up a job to run the query (or your query) every so often during your problem time and capture the output to a table.