Tuesday, December 11, 2012

psql.sh Tool to get session and SQL stats by process_id

Many a times, we want to get database session and SQL information based on the process ID.
Here is the one I've used for many years.


Next time I will show you how to troubleshooting Oracle database performance by this tool.


==
{code start}


#!/bin/bash
if [ $# -ne 1 ]
then
  echo "Usage: psql.sh <ProcessID>"
  exit
fi


sqlplus -S / as sysdba <<+++
set     wrap on
set     feedback off
set     pagesize 0
set termout off

set echo off
set verify off
set arraysize 200
set linesize 200
set trimspool on
set trimout on
set long 5000
set serveroutput on size 200000

/*
-- Get execution plan 
SELECT t.*
FROM v$sql s, table(DBMS_XPLAN.DISPLAY_CURSOR(s.sql_id, s.child_number, format=>'Advanced')) t
where s.sql_id = 'dcfkuagnmqx3y';

SELECT t.*
FROM v$sql s, table(DBMS_XPLAN.DISPLAY_CURSOR(s.sql_id, s.child_number, 'BASIC')) t
where s.sql_id = 'dcfkuagnmqx3y'
and s.last_load_time is not null
and loaded_versions > 0;

provides a way to display the SQL execution plan and SQL execution runtime statistics for cached SQL
cursors based on the information stored in the V$SQL_PLAN and V$SQL_PLAN_STATISTICS_ALL fixed views

*/

Begin

for s in
(select b.sid,b.serial#,b.username, b.machine,b.osuser,
b.program sprogram,c.program pprogram,c.terminal pterminal,b.terminal sterminal,PGA_ALLOC_MEM,
b.process,b.status,b.server,b.type,b.taddr,b.logon_time,b.LAST_CALL_ET,
b.lockwait, c.latchwait,c.latchspin,c.spid,
b.PREV_SQL_ID, b.sql_id,
EVENT, WAIT_TIME, SECONDS_IN_WAIT
from v\$session b, v\$process c
where  c.spid  = $1
and  c.addr  = b.paddr)
loop

--dbms_output.put_line('======================================================');
dbms_output.put_line('SID/Serial  : '|| s.sid||','||s.serial#);
dbms_output.put_line('SQL_ID      : '|| s.sql_id);
dbms_output.put_line('Foreground  : '|| 'PID: '||s.process||' - '||s.sprogram);
dbms_output.put_line('Shadow      : '|| 'PID: '||s.spid||' - '||s.pprogram);
dbms_output.put_line('Terminal    : '|| s.sterminal || '/ ' || s.pterminal);
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, 'Day HH24:MI:SS'));
dbms_output.put_line('Last Call   : '|| to_char(sysdate-(s.last_call_et/60/60/24), 'Day HH24:MI:SS') || ' - ' || to_char(s.last_call_et/60, '990.0') || ' min');
dbms_output.put_line('Lock/ Latch : '|| nvl(s.lockwait, 'NONE')||'/ '||nvl(s.latchwait, 'NONE'));
dbms_output.put_line('Latch Spin  : '|| nvl(s.latchspin, 'NONE'));
dbms_output.put_line('PGA         : '|| s.PGA_ALLOC_MEM);
dbms_output.put_line('Wait        : '|| s.EVENT||': '||s.WAIT_TIME||', Seconds: '||s.SECONDS_IN_WAIT);

dbms_output.put_line('Current SQL statement:');
for c1 in ( select * from v\$sqltext
            where SQL_ID = s.sql_ID order by piece) loop
  dbms_output.put_line(chr(9)||c1.sql_text);
end loop;

for c1 in ( 
SELECT t.*
FROM v\$sql v, table(DBMS_XPLAN.DISPLAY_CURSOR(v.sql_id, v.child_number, 'TYPICAL')) t
where v.sql_id = s.sql_id
and v.loaded_versions > 0

loop
  dbms_output.put_line(chr(9)||c1.PLAN_TABLE_OUTPUT);
end loop;
/*
SELECT *
FROM TABLE(CAST ( DBMS_XPLAN.display_cursor('s.sql_id') AS SYS.DBMS_XPLAN_TYPE_TABLE)) ;
*/
dbms_output.put_line('Previous SQL statement:');
/* for c1 in ( select * from v\$sqltext
            where SQL_ID = s.PREV_SQL_ID order by piece) loop
  dbms_output.put_line(chr(9)||c1.sql_text);
end loop;
*/

for c1 in ( 
/* SELECT * FROM TABLE(CAST ( DBMS_XPLAN.display_cursor(s.prev_sql_id) AS SYS.DBMS_XPLAN_TYPE_TABLE))
*/
SELECT tb.PLAN_TABLE_OUTPUT
FROM v\$sql v, table(CAST ( DBMS_XPLAN.DISPLAY_CURSOR(v.sql_id, v.child_number,'BASIC') AS SYS.DBMS_XPLAN_TYPE_TABLE)) tb
where v.sql_id = s.prev_sql_id
and v.loaded_versions > 0

loop
  dbms_output.put_line(chr(9)||c1.PLAN_TABLE_OUTPUT);
end loop;

dbms_output.put_line('Session Waits:');
for c1 in ( select * from v\$session_wait where sid = s.sid) loop
  dbms_output.put_line(chr(9)||c1.state||': '||c1.event);
  dbms_output.put_line(chr(9)||'Wait time: '||c1.WAIT_TIME||', wait seconds: '||c1.SECONDS_IN_WAIT);
end loop;

dbms_output.put_line('Session History Waits:');
for c1 in ( select * from v\$session_wait_history where sid = s.sid order by seq# asc) loop
  dbms_output.put_line(chr(9)||c1.seq#||': '||c1.event||',Wait time: '||c1.WAIT_TIME);
end loop;

dbms_output.put_line('Session Statistics:');
/* Top session
for c1 in ( select a.statistic#,a.value, b.name, b.class, b.stat_id
 from V\$SESSTAT a, V\$STATNAME b
 where a.STATISTIC# = b.STATISTIC# and sid = s.sid and a.value>0) 
loop
  dbms_output.put_line(chr(9)||c1.statistic#||': '||c1.name||': '||c1.value);
end loop;
*/

End Loop;

END;
/

exit;
+++

{code end}

Example output:


$> psql.sh 26046

SID/Serial  : 33,32215
SQL_ID    : 98g72446puumc
Foreground  : PID: 26043 - sqlplus@mydb02.abc.com (TNS V1-V3)
Shadow    : PID: 26046 - oracle@mydb02.abc.com (TNS V1-V3)
Terminal    : / UNKNOWN
OS User     : oracle on mydb02.abc.com
Ora User    : SYS
Status Flags: ACTIVE DEDICATED USER
Tran Active : 00000000D9569228
Login Time  : Monday 14:27:33
Last Call   : Monday 14:27:33 -    0.3 min
Lock/ Latch : NONE/ NONE
Latch Spin  : NONE
PGA    : 34308772
Wait    : db file scattered read: 0, Seconds: 0

Current SQL statement:
select qt.msgid, e.local_transaction_id, e.source_commit_scn, e.
external_source_pos, e.aq_transaction_id, e.source_transaction_i
d, NVL(e.xidusn, 0), NVL(e.xidslt, 0), NVL(e.xidsqn, 0), NVL(e.f
lags, 0) from "STRMADMIN"."APPLY_QUEUE_TABLE" qt, sys.apply$_err
or e where e.apply#=:1 and qt.enq_tid(+)=e.aq_transaction_id and
qt.q_name(+)=:2 and e.local_transaction_id=:3 order by qt.step
_no
SQL_ID 98g72446puumc, child number 0
-------------------------------------
select qt.msgid, e.local_transaction_id, e.source_commit_scn,
e.external_source_pos, e.aq_transaction_id, e.source_transaction_id,
NVL(e.xidusn, 0), NVL(e.xidslt, 0), NVL(e.xidsqn, 0), NVL(e.flags, 0)
from "STRMADMIN"."APPLY_QUEUE_TABLE" qt, sys.apply$_error e where
e.apply#=:1 and qt.enq_tid(+)=e.aq_transaction_id and qt.q_name(+)=:2
and e.local_transaction_id=:3  order by qt.step_no
Plan hash value: 2690713002
----------------------------------------------------------------------------------------------------------
| Id  | Operation      | Name | Rows  | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      | | | |  3227 (100)| |
|   1 |  SORT ORDER BY      | |     1 |   132 |  3227   (1)| 00:00:39 |
|*  2 |   HASH JOIN OUTER      | |     1 |   132 |  3226   (1)| 00:00:39 |
|*  3 |    TABLE ACCESS BY INDEX ROWID| APPLY$_ERROR |     1 |    75 |     2   (0)| 00:00:01 |
|*  4 |     INDEX UNIQUE SCAN      | STREAMS$_APPLY_ERROR_UNQ |     1 | |     1   (0)| 00:00:01 |
|*  5 |    TABLE ACCESS FULL      | APPLY_QUEUE_TABLE |   566 | 32262 |  3224   (1)| 00:00:39 |
----------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
  2 - access("QT"."ENQ_TID"="E"."AQ_TRANSACTION_ID")
  3 - filter("E"."APPLY#"=:1)
  4 - access("E"."LOCAL_TRANSACTION_ID"=:3)
  5 - filter("QT"."Q_NAME"=:2)
Note
-----
  - dynamic sampling used for this statement (level=2)
Previous SQL statement:
EXPLAINED SQL STATEMENT:
------------------------
select tab.rowid, tab.msgid, tab.corrid, tab.priority, tab.delay,
tab.expiration , tab.exception_qschema,   tab.exception_queue,
tab.chain_no, tab.local_order_no, tab.enq_time,
tab.time_manager_info, tab.state, tab.enq_tid, tab.step_no,
tab.sender_name, tab.sender_address, tab.sender_protocol,
tab.dequeue_msgid, tab.user_prop, tab.user_data  from
"STRMADMIN"."APPLY_QUEUE_TABLE" tab  where q_name = :1 and msgid = :2
Plan hash value: 4210003331
---------------------------------------------------------
| Id  | Operation    | Name |
---------------------------------------------------------
|   0 | SELECT STATEMENT    | |
|   1 |  TABLE ACCESS BY INDEX ROWID| APPLY_QUEUE_TABLE |
|   2 |   INDEX UNIQUE SCAN    | SYS_C004100 |
---------------------------------------------------------
Session Waits:
WAITED SHORT TIME: db file scattered read
Wait time: -1, wait seconds: 0
Session History Waits:
1: db file scattered read,Wait time: 0
2: db file scattered read,Wait time: 0
3: db file scattered read,Wait time: 0
4: db file scattered read,Wait time: 0
5: db file scattered read,Wait time: 0
6: db file scattered read,Wait time: 0
7: db file scattered read,Wait time: 0
8: db file scattered read,Wait time: 0
9: db file scattered read,Wait time: 0
10: db file scattered read,Wait time: 0
Session Statistics:

.
Next time I will show you how to troubleshooting Oracle database performance by this tool.

No comments: