Oracle Scratchpad

February 18, 2007

Logoff Triggers

Filed under: Infrastructure,trace files,Troubleshooting — Jonathan Lewis @ 11:44 pm GMT Feb 18,2007

A few days ago, I described a change to Statspack in 10g that allowed you to see how much time each snapshot took. In that article I suggested copying the code back to 9i; however this is a fiddly little task, and you may prefer to avoid it.

Here’s an alternative – actually a strategy with a much wider use – which does the same, but gives you even better information. Use a “before logoff” trigger to record the information you need. There are lots of ways you could create a suitable trigger;  here’s an example – with just a couple of naughty features that you might want to change:

rem     Script:         log_statspack.sql
rem     Author:         Jonathan Lewis
rem     Dated:          Nov 2006
rem     Purpose:        Simple logoff trigger to monitor statspack

create or replace trigger ses_logoff 
before logoff on perfstat.schema 

        m_output        varchar2(100) := 'Perfstat: ' || 
                                to_char(sysdate,'yyyymmdd hh24:mi:ss');        


        for r in ( 
                        v$mystat        ms, 
                        v$statname      sn 
                        sn.statistic# = ms.statistic# 
                and in ( 
                                'recursive cpu usage', 
                                'session connect time' 
                order by 
        ) loop 
                        r.value < 1000000 
                        r.value := r.value / 100; 
                        r.value := 86400 * ( 
                                        sysdate - ( 
                                                to_date('01-jan-1970','dd-mon-yyyy') + 
                end if;        

                m_output := m_output || to_char(r.value,'9,999,999.99');        

        end loop;        



You’ll notice that I’ve used the undocumented package dbms_system in this trigger. The function ksdwrt() writes to the alert log (use 2 for the first parameter), or the session’s trace file (use 1 for the first parameter) or both (use 3 for the first parameter).

I’ve picked  two statistics from the current session – the CPU used (initially in hundredths of seconds), and the elapsed time since logon. The time the session connected is stored in v$mystat as the number of seconds since 1st Jan 1970, hence the rather odd looking formula for elapsed time.

This script has to be run as sys (or other suitably privileged account) to create the trigger; and after the trigger has been created the perfstat user will write a line to the alert log every time it logs off producing an output like the following:

Perfstat: 20070209 09:25:05          .21         1.00 

Many people already have a utility for picking information from the alert log, but a simple grep (or find) for the expression “Perfstat” will produce a list of times. You could even define the alert log as an external table to pick out the perfstat summary information with SQL.

Odd notes:

My first thought for capturing this information was simply to enable auditing (audit_trail = db in the parameter file), but if you used the spauto.sql script to set statspack running under dbms_job you’ll discover that sessions started by the job queue processes aren’t captured by the normal audit code.

Really you ought to take advantage of the utl_file package to write the output to a separate file rather than dumping it into the alert log – this script is really just a clue about using triggers and v$mystat. You might even decided to write the results into a table in the perfstat schema. (If you do decide to use utl_file, bear in mind that from 9i you no longer need to set the parameter utl_file_dir, the package can use “logical” directories created with the create directory syntax).

You will find that the alert log always shows a date and time stamp above each Perfstat line – this is normal practice; any line that is printed more than a second after the previous line gets a timestamp; I don’t know of any way to stop this happening.

If you try using this example against users logged in as sys, you will find that the “session connect time” for sys always seems to be zero.

Update – Sep 2018

I’ve just seen that, as from, the procedures for writing to the alert log and/or trace files have been moved from dbms_system to package dbms_log. The four procedures are:

  • ksdwrt – write to file
  • ksdind – index
  • ksdddt – date stamp
  • ksdfls – flush to disc

More details, with examples, in this blog note.


  1. always nice to see your ideas.
    I’m sure you know ansi date literals – the fixed date format spares typing some letters
    date ‘1970-01-01′
    instead of

    Comment by Martin — February 19, 2007 @ 9:44 am GMT Feb 19,2007 | Reply

  2. Hi Jonathan,

    You obviously point out that its a bit naughty to use dbms_system.ksdwrt. I blogged about this function a long time ago and the security issues related to it. Your readers may be interested. See and



    Comment by Pete Finnigan — February 19, 2007 @ 5:22 pm GMT Feb 19,2007 | Reply

RSS feed for comments on this post. TrackBack URI

Comments and related questions are welcome.

Fill in your details below or click an icon to log in: Logo

You are commenting using your account. Log Out /  Change )

Google photo

You are commenting using your Google account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Website Powered by