Monitoring a session activity
Scenario:
There is an application, in which there are 100 users and for this 100 users, consider there is 1 tab/page. After clicking a tab in the application all 99 users are able get the results out of the tab as quick as possible, but only 1% whenever he clicks on the tab it will take lot of time to load the page, and if all the tabs are working fine thenonly 1 tab when he actually clicks if it is taking long time defintely that user raised a issue to the support team and it might reach to database team to look into it.
Now you have to analyze the 1% user, whenever he clicking the tab what is actual happening in the database.
SQL> select sid,serial#, from v$session where username='SCOTT';
SID SERIAL#
---------- ----------
24 15
SQL> select s.sid,s.sql_id,p.spid from v$session s, v$process p where s.sid=24 and s.paddr=p.addr;
SIDSQL_ID SPID
----------------------
24 2472
SQL> !ps -ef | grep 2472
oracle 2472 1 0 09:20 ? 00:00:00 oracleORADB (LOCAL=NO)
oracle 2490 2257 0 09:27 pts/0 00:00:00 /bin/bash -c ps -ef | grep 2472
oracle 2492 2490 0 09:27 pts/0 00:00:00 grep 2472
SQL> EXEC DBMS_SYSTEM.set_sql_trace_in_session(sid=>24, serial#=>15, sql_trace=>TRUE); --- To enable trace
SQL> select * from emp;
SQL> select * from dept;
SQL> select * from salgrade;
SQL> EXEC DBMS_SYSTEM.set_sql_trace_in_session(sid=>24, serial#=>15, sql_trace=>FALSE); --- To disable trace
SQL> show parameter user
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
license_max_users integer 0
parallel_adaptive_multi_user boolean TRUE
redo_transport_user string
user_dump_dest string /oracle/base/diag/rdbms/oradb/QADB/trace
[oracle@OEL-11g trace]$ ls -ltr *2472*
-rw-r----- 1 oracle oinstall 315 Oct 2 09:33 QADB_ora_2472.trm
-rw-r----- 1 oracle oinstall 23582 Oct 2 09:33 QADB_ora_2472.trc
[oracle@OEL-11g trace]$ tkprof ORADB_ora_2472.trc /home/oracle/sql_trace.oitut sys =no
Note: If you choose sys=no it will not capture sys operations.
-rw-r--r-- 1 oracle oinstall 5902 Oct 1 09:38 ctl.bkp
-rw-r--r-- 1 oracle oinstall 5943 Oct 2 09:37 sql_trace.out
[oracle@OEL-11g ~]$
[oracle@OEL-11g ~]$ more sql_trace.out
TKPROF: Release 11.2.0.3.0 - Development on Fri Oct 2 09:37:59 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: ORADB_ora_2472.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
SQL ID: 3154rqzb8xudy Plan Hash: 3383998547
select * from emp;
--More--(13%)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.05 4 58 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.01 2 3 0 4
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.01 0.07 6 61 0 4
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 85
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
4 4 4 TABLE ACCESS FULL DEPT (cr=3 pr=2 pw=0 time=13922 us cost=3 size=80 c
ard=4)
********************************************************************************
SQL ID: a2dk8bdn0ujx7 Plan Hash: 3956160932
select * from dept;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 73 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 6 3 0 14
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 6 76 0 14
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 85
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
14 14 14 TABLE ACCESS FULL EMP (cr=3 pr=6 pw=0 time=2150 us cost=3 size=532 ca
rd=14)
********************************************************************************
SQL ID: 30p00zk91247c Plan Hash: 2489195056
select * from salgrade;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 6 3 0 5
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 6 3 0 5
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 85
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
5 5 5 TABLE ACCESS FULL SALGRADE (cr=3 pr=6 pw=0 time=2214 us cost=3 size=5
0 card=5)
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.01 0.06 4 131 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 6 0.00 0.01 14 9 0 23
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 12 0.01 0.08 18 140 0 23
Misses in library cache during parse: 3
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 51 0.00 0.00 0 0 0 0
Fetch 73 0.00 0.02 4 165 0 51
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 124 0.00 0.02 4 165 0 51
Misses in library cache during parse: 0
3 user SQL statements in session.
13 internal SQL statements in session.
16 SQL statements in session.
********************************************************************************
Trace file: ORADB_ora_2472.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
3 user SQL statements in trace file.
13 internal SQL statements in trace file.
16 SQL statements in trace file.
16 unique SQL statements in trace file.
283 lines in trace file.
8 elapsed seconds in trace file.
No comments:
Post a Comment