Pages

Sunday, December 22, 2019

Monitoring a session activity

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