JL Computer Consultancy

How much work did a session do?

May 2005


A recent question on the comp.databases.oracle.server newsgroup asked:  “I think there is a session that is doing too many commits – how can I find out which one it is?”

The immediate answer is to check v$sesstat (joined to v$statname) to find the session with a very large number for the statistic “user commits” – although the statistic “calls to kcmgas might be better, as this will also count any rolback that had something to roll back. However, if the session doesn’t happen to be alive when you check, what can you do?

A simple (temporary) method I have used for some time is to dump each session’s work load as the session terminates by creating a logoff trigger.

The implementation is not ‘nice’, because it creates an object in the SYS schema, takes advantage of an undocumented package, and generates a trace file that is typically 5KB – 8KB for each session that logs off – and some applications get through a lot of sessions in a day. But used with care and attention for a brief period, it can be very helpful.

As it stands, the trigger is created against a single schema – change the commenting if you want to create it against the entire database.


rem

rem   Script:           trap_work_2.sql

rem   Author:           Jonathan Lewis

rem   Dated:            Apr 2003

rem   Purpose:          Create simple trigger to capture work details from sessions.

rem

rem   Notes:

rem   Last tested 10.1.0.4

rem   Last tested  9.2.0.6

rem   Last tested  8.1.7.4

rem

rem   Create a session logoff trigger.

rem

rem   This script has to be run by the sys account.

rem

rem   I prefer to write to the trace file rather

rem   than store the data in the database.

rem

rem   You could use array fetches rather than cursor for loops

rem

 

create or replace trigger ses_logoff

-- before logoff on database

before logoff on test_user.schema

declare

 

      m_username        v$session.username%type;

      m_osuser          v$session.osuser%type;

      m_program         v$session.program%type;

      m_machine         v$session.machine%type;

 

begin

      dbms_system.ksdwrt(1,'===========================');

      dbms_system.ksdddt;

      dbms_system.ksdwrt(1,'===========================');

 

 

      select

            username, osuser, machine, program

      into 

            m_username, m_osuser, m_machine, m_program

      from

            (select /*+ no_merge */ sid from v$mystat where rownum = 1) ms,

            V$session                                       se

      where se.sid = ms.sid

      ;

 

      dbms_system.ksdwrt(1, 'Schema:       ' || m_username);

      dbms_system.ksdwrt(1, 'User:         ' || m_osuser);

      dbms_system.ksdwrt(1, 'Program:      ' || m_program);

      dbms_system.ksdwrt(1, 'Machine:      ' || m_machine);

 

      dbms_system.ksdwrt(1,rpad('=',105,'='));

 

      dbms_system.ksdwrt(1,rpad('Statistic',60) || lpad('Value',28));

      dbms_system.ksdwrt(1,rpad('---------',60) || lpad('-----',28));

 

      for r in (

            select

                  sn.name,

                  ms.value

            from

                  v$mystat    ms,

                  v$statname  sn

            where

                  ms.value != 0

            and   sn.statistic# = ms.statistic#

      ) loop

            dbms_system.ksdwrt(

                  1,

                  rpad(r.name,60) ||

                  to_char(r.value,'999,999,999,999,999,999,999')

            );

      end loop;

 

      dbms_system.ksdwrt(1,rpad('=',105,'='));

 

      dbms_system.ksdwrt(

            1,

            rpad('Event',60) ||

            lpad('Waits',11) ||

            lpad('Timeouts',11) ||

            lpad('Time (c/s)',11) ||

            lpad('Max (c/s)',11)

      );

 

      dbms_system.ksdwrt(

            1,

            rpad('-----',60) ||

            lpad('-----',11) ||

            lpad('--------',11) ||

            lpad('----------',11) ||

            lpad('---------',11)

      );

 

      for r in (

            select

                  event, total_waits, total_timeouts, time_waited, max_wait

            from

                  (select /*+ no_merge */ sid from v$mystat where rownum = 1) ms,

                  V$session_event                                       se

            where

                  total_waits != 0

            and   se.sid = ms.sid

      ) loop

            dbms_system.ksdwrt(

                  1,

                  rpad(r.event,60) ||

                  to_char(r.total_waits,    '99,999,999') ||

                  to_char(r.total_timeouts, '99,999,999') ||

                  to_char(r.time_waited,    '99,999,999') ||

                  to_char(r.max_wait,       '99,999,999')

            );

      end loop;

 

      dbms_system.ksdwrt(1,rpad('=',105,'='));

 

end;

/

 


A couple of notes:

dbms_system.ksdwrt writes to the trace file if the first parameter is 1, to the alert log if the parameter is 2, and to both if it is 3.

dbms_system.ksdddt writes a date stamp to the current target.


Footnote:

For a cheaper, but much less informative, implementation you could simply enable database auditing, and audit ‘create session’. Each session will then leave one row in dba_audit_session (a view of the sys.aud$ table) showing how much work it has done in terms of logical I/O, physical I/O, and CPU time. Don’t forget to clear out sys.aud$ on a regular basis if you do this.

As a general principle – any batch-like code you run should execute the queries for its session statistics and waits before it ends, and record the results somewhere. This is a very good pre-emptive measure that is (a) cheap, but (b) could give you some critical information any time your batch over-runs its time-window.


Back to Index of Topics