Link to home
Start Free TrialLog in
Avatar of dbaSQL
dbaSQLFlag for United States of America

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;
Avatar of Sean Stuber
Sean Stuber

what version are you using?  if it's 10g or higher then it's even easier to find.


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.
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
Avatar of dbaSQL

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?
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.
Avatar of dbaSQL

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
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.
Avatar of dbaSQL

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.
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?
Avatar of dbaSQL

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.
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 = ....
Avatar of dbaSQL

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,session_state,sql_opname,sql_exec_start,blocking_session_status,blocking_session,program,machine

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.
Avatar of dbaSQL

ASKER

This is the new statement:  

SELECT sample_id,session_id,session_state,sql_id,sql_opname,sql_exec_start,blocking_session_status,blocking_session,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
Avatar of dbaSQL

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,session_state,sql_id,sql_opname,sql_exec_start,blocking_session_status,blocking_session,program,machine from v$active_session_history where session_id = 575 and sample_time > '20-NOV-16';
ASKER CERTIFIED SOLUTION
Avatar of Sean Stuber
Sean Stuber

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Avatar of dbaSQL

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.
Avatar of dbaSQL

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.
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
Avatar of dbaSQL

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.
>>> 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
Avatar of dbaSQL

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?
Avatar of dbaSQL

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.