During my previous test with Unified Auditing Policies anomalies after upgrade to Oracle 19c, I also hit and error when I queried the unified audit trail. Hence, I make a reminder to myself and would like explain what to do in case you are Receiving ORA-55940: An error occurred during execution of ktliIngestExternData as well.
Photo by Moritz Mentges on Unsplash
What a strange error
I created a few policies by myself and did a database upgrade from Oracle 12.2.0.1 to Oracle 19.8.0. And after upgrade, I wanted to check the records in my audit trail. But instead of a number or the contents, I received this strange error:
select count(*), action_name, unified_audit_policies from cdb_unified_audit_trail group by action_name, unified_audit_policies order by 1 desc; select count(*), action_name, unified_audit_policies * ERROR at line 1: ORA-55940: An error occurred during execution of ktliIngestExternData.
Oddly enough, MyOracle Support is not your best friend in this case.
Search on MyOracle Support does not give any result for ORA-55940
But luckily using an external search engine helps and leads to several blog posts. So I’m not the only one hitting this issue.
Potential Solutions?
From these blogs (find them in the “Links” section at the end) I learned that there are two components to the Audit Trail, the AUDSYS schema in the database and the spillover files on disk.
- Check AUDSYS schema:
SQL> select count(*) from audsys.aud$unified; COUNT(*) ---------- 80
Works.
- Check the spillover audit files:
SQL> select count(*) from x$unified_audit_trail; select count(*) from x$unified_audit_trail * ERROR at line 1: ORA-55940: An error occurred during execution of ktliIngestExternData.Aha. So here I have an issue.
Thanks to Christian Pfundtner for this analysis and explanation.
So I climbed down to my spillover files:
[DB12] oracle@hol:/u01/app/oracle/audit/DB12 $ ls -lrt total 19272 -rw-------. 1 oracle dba 2560 Oct 20 21:41 ora_audit_0327.bin -rw-------. 1 oracle dba 1024 Oct 20 21:41 ora_audit_10.bin -rw-------. 1 oracle dba 1427456 Oct 20 21:43 ora_audit_0171.bin -rw-------. 1 oracle dba 2376704 Oct 20 21:57 ora_audit_0173.bin -rw-------. 1 oracle dba 2119168 Oct 20 21:58 ora_audit_0328.bin -rw-------. 1 oracle dba 4932096 Oct 20 22:01 ora_audit_0334.bin -rw-------. 1 oracle dba 6076416 Oct 20 22:05 ora_audit_0332.bin -rw-------. 1 oracle dba 112128 Oct 20 22:07 ora_audit_017.bin -rw-------. 1 oracle dba 3584 Oct 20 22:07 ora_audit_0168.bin -rw-------. 1 oracle dba 1863168 Oct 20 22:07 ora_audit_015.bin -rw-------. 1 oracle dba 22528 Oct 20 22:11 ora_audit_0329.bin -rw-------. 1 oracle dba 2560 Oct 20 22:13 ora_audit_0335.bin -rw-------. 1 oracle dba 4096 Oct 20 22:15 ora_audit_0336.bin -rw-------. 1 oracle dba 11264 Oct 20 22:16 ora_audit_00.bin -rw-------. 1 oracle dba 4096 Oct 20 22:16 ora_audit_0317.bin -rw-------. 1 oracle dba 19968 Oct 20 22:16 ora_audit_0169.bin -rw-------. 1 oracle dba 698880 Oct 20 22:16 ora_audit_014.bin
And following Geodata Master’s recommendation, I tried to load them into the AUDSYS schema at first:
SQL> exec DBMS_AUDIT_MGMT.LOAD_UNIFIED_AUDIT_FILES; BEGIN DBMS_AUDIT_MGMT.LOAD_UNIFIED_AUDIT_FILES; END; * ERROR at line 1: ORA-14300: partitioning key maps to a partition outside maximum permitted number of partitions ORA-06512: at "AUDSYS.DBMS_AUDIT_MGMT", line 5815 ORA-06512: at "AUDSYS.DBMS_AUDIT_MGMT", line 435 ORA-06512: at "AUDSYS.DBMS_AUDIT_MGMT", line 5797 ORA-06512: at line 1
Oh.
At least, in this case MOS was helpful as it revealed MOS Note: 2619616.1 – ORA-14300 On DBMS_AUDIT_MGMT.LOAD_UNIFIED_AUDIT_FILES() as first result to my search with the above error pattern. Without referencing a bug, the Note recommends to just delete the *.bin spillover files.
$ORACLE_BASE/audit/$ORACLE_SID rm *.bin
Well, I’d rather move them away as Christian did, too.
But before doing so, I recognized an interesting change since I tried to load the records into my database: Some of the files have been deleted already, I guess during the load into AUDSYS which then failed with the ORA-14300 above.
[DB12] oracle@hol:/u01/app/oracle/audit/DB12 $ ls -lrt total 24 -rw-------. 1 oracle dba 2560 Oct 20 21:41 ora_audit_0327.bin -rw-------. 1 oracle dba 1024 Oct 20 21:41 ora_audit_10.bin -rw-------. 1 oracle dba 2560 Oct 21 09:12 ora_audit_023.bin -rw-------. 1 oracle dba 11264 Oct 21 09:13 ora_audit_00.bin
As MOS Note: 2619616.1 mentions that my database has to be in a “non-writable” state, I’d shut it down before moving the files out of sight.
But unfortunately, I got stuck again.
SQL> select count(*) from x$unified_audit_trail;
select count(*) from x$unified_audit_trail
*
ERROR at line 1:
ORA-55940: An error occurred during execution of ktliIngestExternData.
The other directory the note points to, is empty in my case:
/u01/app/oracle/product/19/rdbms/audit
The same applies to the directory in source:
/u01/app/oracle/product/12.2.0.1/rdbms/audit
Now I felt a bit lost.
“My” Solution
At some point, only the sledgehammer approach helps.
rm -rf /u01/app/oracle/audit/DB12
Then I restarted my database.
And magic magic … hurray!
SQL> startup force ORACLE instance started. Total System Global Area 1258290752 bytes Fixed Size 8896064 bytes Variable Size 369098752 bytes Database Buffers 872415232 bytes Redo Buffers 7880704 bytes Database mounted. Database opened. SQL> select count(*) from x$unified_audit_trail; COUNT(*) ---------- 8
It works. The directory gets recreated afterwards.
Luckily I have snapshots. I was really curious if this problem was evident before upgrade already. But the query worked flawless in 12.2.0.1 before upgrade.
This was my $ORACLE_BASE/audit/DB12 directory before upgrade:
[DB12] oracle@hol:/u01/app/oracle/audit drwxr-x---. 2 oracle dba 4096 Oct 20 20:45 DB12 $ cd DB12/ [DB12] oracle@hol:/u01/app/oracle/audit/DB12 $ ls -lrt total 16 -rw-------. 1 oracle dba 1024 Oct 20 20:45 ora_audit_00.bin -rw-------. 1 oracle dba 1024 Oct 20 20:45 ora_audit_0317.bin -rw-------. 1 oracle dba 3072 Oct 20 20:45 ora_audit_0168.bin -rw-------. 1 oracle dba 1536 Oct 20 20:45 ora_audit_0320.bin
And this is how it looked after upgrade to 19.8.0:
$ cd $ORACLE_BASE/audit [DB12] oracle@hol:/u01/app/oracle/audit $ ls -lrt drwxr-x---. 2 oracle dba 4096 Oct 20 22:13 DB12 $ cd DB12 [DB12] oracle@hol:/u01/app/oracle/audit/DB12 $ ls -lrt total 19272 -rw-------. 1 oracle dba 2560 Oct 20 21:41 ora_audit_0327.bin -rw-------. 1 oracle dba 1024 Oct 20 21:41 ora_audit_10.bin -rw-------. 1 oracle dba 1427456 Oct 20 21:43 ora_audit_0171.bin -rw-------. 1 oracle dba 2376704 Oct 20 21:57 ora_audit_0173.bin -rw-------. 1 oracle dba 2119168 Oct 20 21:58 ora_audit_0328.bin -rw-------. 1 oracle dba 4932096 Oct 20 22:01 ora_audit_0334.bin -rw-------. 1 oracle dba 6076416 Oct 20 22:05 ora_audit_0332.bin -rw-------. 1 oracle dba 112128 Oct 20 22:07 ora_audit_017.bin -rw-------. 1 oracle dba 3584 Oct 20 22:07 ora_audit_0168.bin -rw-------. 1 oracle dba 1863168 Oct 20 22:07 ora_audit_015.bin -rw-------. 1 oracle dba 22528 Oct 20 22:11 ora_audit_0329.bin -rw-------. 1 oracle dba 2560 Oct 20 22:13 ora_audit_0335.bin -rw-------. 1 oracle dba 4096 Oct 20 22:15 ora_audit_0336.bin -rw-------. 1 oracle dba 11264 Oct 20 22:16 ora_audit_00.bin -rw-------. 1 oracle dba 4096 Oct 20 22:16 ora_audit_0317.bin -rw-------. 1 oracle dba 19968 Oct 20 22:16 ora_audit_0169.bin -rw-------. 1 oracle dba 698880 Oct 20 22:16 ora_audit_014.bin
Except for the fact that the database generated quite a number of new spillover audit files during upgrade, I can’t see any change in terms of “permissions” or “ownership”.
Now I was even more curious.
Does it work also without taking the database down as I did initially?
Yes, it does!
$ rm -rf DB12 [DB12] oracle@hol:/u01/app/oracle/audit $ sqlplus / as sysdba SQL*Plus: Release 19.0.0.0.0 - Production on Wed Oct 21 09:33:43 2020 Version 19.8.0.0.0 Copyright (c) 1982, 2020, Oracle. All rights reserved. Connected to: Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production Version 19.8.0.0.0 SQL> select count(*) from x$unified_audit_trail; COUNT(*) ---------- 0
Strange errors sometimes require a sledgehammer solution.
Further Information and Links
- Geodata Master: ORA-55940
- DBA Masters (Christian Pfundtner): ORA-55940
- MOS Note: 2619616.1 – ORA-14300 On DBMS_AUDIT_MGMT.LOAD_UNIFIED_AUDIT_FILES()
- Check your Unified Auditing Policies after upgrading to Oracle 19c
–Mike
Hello,
you can also cleanup all rows from Unif. audit by this command. Restart is not needed to solve this problem …
Regards Jan
exec DBMS_AUDIT_MGMT.CLEAN_AUDIT_TRAIL(audit_trail_type => DBMS_AUDIT_MGMT.AUDIT_TRAIL_UNIFIED, use_last_arch_timestamp => FALSE);
Hi Jan,
actually I mentioned at the end of the blog post, that I didn’t need to take down my database. Only the MOS note proposed this as part of the solution which did not work for me.
And thanks, I didn’t try cleaning up the entire trail.
Cheers,
Mike
Hi Mike,
My Audit logs are flooded due to the SCHEMA export activity. The user I used to export the schema is being audited for ALL actions.
Now the issue is I can see millions of rows in AUDSYS.AUD$UNIFIED but I am not able to query UNIFIED_AUDIT_TRAIL (it runs forever).
SELECT COUNT(*) from X$UNIFIED_AUDIT_TRAIL also runs forever. When I checked my spill over files it has grown around 10GB.
Reason : SYSAUX tablespace was full due to audit logs flooding and that is when DB started writing OS spillover files.
By the time my schema export was completed I already ended up creating 10GB of spillover files.
I would need your advise on this issue. Note I already have an SR#3-25623457171 ongoing.
Appreciate your advise.
Please note :
Database version : 19.10.0.0 on Windows 2012 R2
UNIFIED_AUDIT_TRAIL is MIXED Mode
Thanks !!
Dabir
Hi Dabir,
this sounds terrible – and you are not the first customer reporting such issues.
I guess you have read this blog post, too, already?
https://mikedietrichde.com/2020/10/21/check-your-unified-auditing-policies-after-upgrading-to-oracle-19c/
This could be the reason for the ALL change.
You please need to open an SR – and update the comments section here with the SR number.
Cheers,
Mike
Hi Mike,
Appreciate your response !!
Yes I have gone through the link and verified for ALL audit_actions in my Prod DB. We have also upgraded this database from 12.2.0.1 to 19c last November.
I have created this SR# : SR 3-25623457171
Thank you !!
Regards,
Dabir
Hi Mike,
I found the reason that x$unified_audit_trail gives an error.
When you use ‘strings’ you will see that all the files contain ‘ANG Spillover Audit File’. However, most files also contain other info. When I deleted the files that contained nothing else than ‘ANG Spillover Audit File’ (8 out of 230), I was able to query the table again without errors.
As it had to do with reading the info from the files (ktliIngestExternData), that seemed a good approach to me. Apparently the function cannot handle ‘null’ info.
For a moment I thought all files were just 512 bytes, but i checked and size is not a good way to detect those files (512 or 1024 bytes). What workde fine for me was. A file that gives a 0 causes an error in the database.
> for i in `ls *`; do echo $i ; strings -f $i | grep -v Spillover | wc -l; done
Kind regards,
Jan Broos
OMG – thanks Jan, this is a workaround I wasn’t aware of. And it sounds weird at best to be faced with such a problem.
Thanks for digging deep into the topic and sharing your workaround!
Cheers,
Mike
Hi Mike,
You know how that kind of thinks work. It was a nice brainteaser. And after all, didnt take to much effort.
Another teaser with the spillover files is how to load. I am able to load them as SYS, but not as a user with AUDIT_ADMIN (and DBA) role granted. Didn’t figure that out yet (running on 19.13)
kind regards,
Jan Broos
Thanks Jan!!
Cheers,
Mike
this saved me, 4 node RAC, 19.13, any query on unified_audit_trail or the gv$unified_audit_trail was generating ORA 7445 [kzafp_save_n_getmore] on specific instance, narrowed it down in plan to object was the X$ table taking longest which led me to this note, on the node there were some spillover files for the instance, only small few and small in size, dropping folder fixed problem instantly . Super note!
as they were small in size I guessed that it was the content rather than quantity which matches Jans observation as well but I didnt dive into them to see before clearing out. hth