Oracle Scratchpad

June 1, 2011


Filed under: audit,Oracle,Troubleshooting,Upgrades — Jonathan Lewis @ 5:42 pm BST Jun 1,2011

Here’s an example of how the passing of time can allow a problem to creep up on you.

A recent client had a pair of logon/logoff database triggers to capture some information that wasn’t available in the normal audit trail, and they had been using these triggers successfully for many years, but one day they realised that the amount of redo generated per hour had become rather large, and had actually been quite bad and getting worse over the last few months for no apparent reason. (You’ve heard this one before … “honest, guv, nothing has changed”).

Here’s a clue to their problem. Their logoff trigger updated their own auditing table with the following code (although I’ve removed some columns) :

        if sys_context('USERENV', 'SESSIONID') = 0 then 
                update system.user_audit a 
                        logoff_time = sysdate 
                where    audsid = sys_context('USERENV', 'SESSIONID') 
                and     logon_time = (
                                select  max(logon_time) 
                                from    system.user_audit b 
                                where   b.audsid = a.audsid 
                update system.user_audit 
                        logoff_time = sysdate
                where   audsid = sys_context('USERENV', 'SESSIONID'); 
        end if; 

The table was suitably indexed to make the correlated update (“most recent of” subquery) operate very efficiently, so that wasn’t the problem.

You might question the validity of updating just the rows with the most recent date when the sys_context(‘userenv’,’sessioned’) is zero, and why the SQL to do the update doesn’t then use literal zeros rather than calling the sys_context() function and using a correlation column – but those are minor details.

You might wonder why zero is a special case, of course, but then you may recall that when a user connects as SYS the audsid is zero – so this code is attempting to limit the update to just the row created by the most recent logon by SYS, which may introduce a few errors but really SYS shouldn’t be connecting to a production system very often.

At this point you might ask which version of Oracle the client was running. They had started using Oracle a long time ago, but this system had gone through Oracle 9i, and was now running 10g; and if you’ve kept an eye on things like autotrace you may have noticed that the audsid used by any SYS session changed from zero to 4294967295 in the upgrade to 10g. So this code is no longer treating SYS as a special case.

By the time I was on site, the client’s audit table held about 87,000 rows for the audsid 4294967295, and every time SYS logged off the session would update every single one of them. (It took a few seconds and about 45 MB of redo for SYS to log off – and SYS sessions connected rather more frequently than expected).


If you still have to get through the upgrade from 8i or 9i to 10g, then watch out for code that does things with the deprecated userenv(‘sessionid’) or sys_context(‘userenv’,’sessionid’).


  1. So how many files did they have in $ORACLE_BASE/admin/$ORACLE_SID/adump ? And how many of those correlate with rman and other scheduled jobs? And did anyone notice?

    Comment by joel garry — June 1, 2011 @ 11:04 pm BST Jun 1,2011 | Reply

    • Joel,

      I didn’t check – I probably should have, but we were chasing other problems at the time.

      This note was about a “user-defined” audit, though, not the builtin “audit_trail=db” thing. I don’t think you get the adump files unless you’ve set the “audit_sys_operations” parameter (and that might not be exactly the right name) to true.

      Comment by Jonathan Lewis — June 2, 2011 @ 8:50 pm BST Jun 2,2011 | Reply

  2. See MOS AUDIT_SYS_OPERATIONS Set To FALSE Yet Audit Files Are Generated [ID 308066.1]
    One of those obvious things so many people forget about, and doesn’t have the obvious “so when did they disconnect?” that everyone would want to know, so they write logoff triggers to trip over after an upgrade. Every sysoper connection makes a file, at least several per day at most sites, a forehead-slapper when noticed after a couple of years.

    Comment by joel garry — June 2, 2011 @ 9:37 pm BST Jun 2,2011 | Reply

    • Joel,

      Thanks for that bit of information. That’s a nice example of a “little oddity” that eventually can become a big problem – at least for a while – when “nothing changed” (except the passage of time).

      Comment by Jonathan Lewis — June 4, 2011 @ 10:18 am BST Jun 4,2011 | Reply

  3. To solve this problem,I prefer to use userenv(‘SID’) .
    First, It is much efficient, use id to query v$session, we use the index on x$ksuse(Kernel Service User SEssion).
    Second, we use sid + serial# to assure this field to be nearly unique.

    Comment by jametong — June 3, 2011 @ 7:17 am BST Jun 3,2011 | Reply

    • Jametong,

      The problem, though, is that you have to know that things have changed and what new alternatives there are to solve them.

      Without checking I can’t be too sure, but there was a time when userenv() didn’t have “SID” as an option – so your approach is also dependent on the passing of time. (It’s better practice to use sys_context(‘userenv’,’sid’) by the way, the userenv() calls were deprecated in 9i – even though Oracle still uses userenv(‘instance’) to pick a v$ from a gv$).

      Speaking of instances, your approach would also need the instance number to complete the identification, and also has the problem that the serial# resets on instance restart – so won’t be appropriate for everybody.

      Comment by Jonathan Lewis — June 4, 2011 @ 10:24 am BST Jun 4,2011 | Reply

  4. […] Jonathan Lewis presents an example of how the passing of time can allow a problem to creep up on […]

    Pingback by Log Buffer #223, A Carnival of the Vanities for DBAs | The Pythian Blog — June 3, 2011 @ 8:27 am BST Jun 3,2011 | Reply

  5. […] throw error messages.  You might find that the following SQL statement (based on the contents of this article) returns different values for the SYS user depending on the Oracle Database release […]

    Pingback by Unique Index Result Error with Ref Cursor on Oracle 11g but Not on 10g « Charles Hooper's Oracle Notes — June 6, 2011 @ 12:01 pm BST Jun 6,2011 | Reply

  6. […] lucky, or impossibly thorough. Would you, for example, have noticed pre-upgrade that Oracle changed sys_context(‘userenv’,’sessionid’) from zero to 4294967295 for the sys schema and realised the significance this would have on your […]

    Pingback by Upgrades | Oracle Scratchpad — June 13, 2017 @ 12:15 pm BST Jun 13,2017 | 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 )

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

%d bloggers like this: