Monday, April 30, 2012

ORA-09925: Unable to create audit trail file

Sometimes the issues you hit make no sense at all. Consider the following when things behaving normally:
[oracle@ora11gr2 ~]$ export ORACLE_SID=test
[oracle@ora11gr2 ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.3.0 Production on Mon Apr 30 17:09:31 2012

Copyright (c) 1982, 2011, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> exit
Disconnected
I have no instance named test running on the box and get the expected behavior. Now let's continue:
[oracle@ora11gr2 ~]$ touch /tmp/test
[oracle@ora11gr2 ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.3.0 Production on Mon Apr 30 17:10:54 2012

Copyright (c) 1982, 2011, Oracle.  All rights reserved.

ERROR:
ORA-09925: Unable to create audit trail file
Linux-x86_64 Error: 2: No such file or directory
Additional information: 9925
ORA-09925: Unable to create audit trail file
Linux-x86_64 Error: 2: No such file or directory
Additional information: 9925
The only thing I changed is created an empty file /tmp/test and suddenly I'm getting some "ORA-09925: Unable to create audit trail file" errors? What's going on? If we strace SQL*Plus we would see the following:
3798  stat("/u01/app/oracle/admin/test/adump", 0x7fff1a8b5bd0) = -1 ENOENT (No such file or directory)
3798  access("/tmp/test", F_OK)         = 0
3798  open("/u01/app/oracle/product/11.2.0/dbhome_2/rdbms/audit//tmp/test_ora_3798_1.aud", O_RDWR|O_CREAT|O_EXCL, 0660) = -1 ENOENT (No such file or directory)
The first command checks for audit file directory in a default location. However, the second pair of commands does something strange. It tests whether file /tmp/test exists and if it does it tries to open an audit trace file under a really weird path. But where does this path comes from? If I look at my environment variables:
[oracle@ora11gr2 ~]$ env | grep /tmp
ORACLE_PATH=/tmp
Apparently I have some strange ORACLE_PATH variable set. What if I unset it?
[oracle@ora11gr2 ~]$ unset ORACLE_PATH
[oracle@ora11gr2 ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.3.0 Production on Mon Apr 30 17:22:27 2012

Copyright (c) 1982, 2011, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> exit
Disconnected
Strangely enough everything works normally again! So what I discovered is the following:
  1. When you run "sqlplus / as sysdba" SQL*Plus will check whether you have ORACLE_PATH environment variable set.
  2. If you do, it looks up a file named $ORACLE_PATH/$ORACLE_SID.
  3. If such a file exists you will get the above behavior.
I found this to be a very odd behavior if not outright confusing especially if you happened to have the above conditions met (which, in fact, did happen to me on a real system). A quick search on MOS revealed the following:
Bug 13584524: STRANGE AUDIT DESTINATION IF ORACLE_PATH IS SET: ORA-09925
For now the bug appears to be affecting only 11.2.0.3 regardless of the platform.