It is bad to realize, after a few years, that my customer’s Audit Cleanup procedures are not working properly for every database…
NOTE: The post is based on standard audit, not unified audit.
My customer developed a quite nice procedure for database housekeeping (including diag dest, OS audit trail, recyclebin, DB audit…)
But after some performance problems, I have come across the infamous sql_id 4ztz048yfq32s:
|
1 2 3 |
SELECT TO_CHAR(current_timestamp AT TIME ZONE 'GMT', 'YYYY-MM-DD HH24:MI:SS TZD') AS curr_timestamp, COUNT(username) AS failed_count, TO_CHAR(MIN(timestamp), 'yyyy-mm-dd hh24:mi:ss') AS first_occur_time, TO_CHAR(MAX(timestamp), 'yyyy-mm-dd hh24:mi:ss') AS last_occur_time FROM sys.dba_audit_session WHERE returncode != 0 AND timestamp >= current_timestamp - TO_DSINTERVAL('0 0:30:00') |
This SQL comes from the “Failed Logon Attempts” metric in Enterprise Manager.
I’ve checked the specific database, and the table SYS.AUD$ was containing way too many rows, dating before our purge time:
|
1 2 3 4 5 6 7 8 9 10 11 |
SQL> select min(timestamp) from dba_audit_session; MIN(TIMESTAMP) ------------------- 04.02.2017 07:01:20 SQL> select dbid, count(*) from aud$ group by dbid; DBID COUNT(*) ---------- ---------- 2416611527 35846477 |
The cleanup procedure does basically this:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
SQL> begin 2 dbms_audit_mgmt.set_last_archive_timestamp(audit_trail_type => DBMS_AUDIT_MGMT.AUDIT_TRAIL_AUD_STD 3 ,last_archive_time => SYSTIMESTAMP-31); 4 end; 5 / PL/SQL procedure successfully completed. SQL> set timing on SQL> begin 2 dbms_audit_mgmt.clean_audit_trail( 3 audit_trail_type => sys.dbms_audit_mgmt.AUDIT_TRAIL_AUD_STD, 4 use_last_arch_timestamp => TRUE); 5 end; 6 / PL/SQL procedure successfully completed. Elapsed: 00:00:38.34 |
But despite a retention window of 31 days, the rows are still there:
|
1 2 3 4 5 6 7 |
SQL> select min(timestamp) from dba_audit_session; MIN(TIMESTAMP) ------------------- 04.02.2017 07:01:20 Elapsed: 00:00:29.06 |
(today is 27.04.2018, so the oldest records are more than 1 year old)
I’ve checked with ASH, the actual delete statement executed by the clean_audit_trail procedure is:
|
1 |
DELETE FROM SYS.AUD$ WHERE DBID = 2416611527 AND NTIMESTAMP# < to_timestamp('2017-02-04 05:01:10', 'YYYY-MM-DD HH24:MI:SS.FF') AND ROWNUM <= 140724603463440 |
So, the DBID clause is OK, but the NTIMESTAMP# clause is not!
Why?
Long story long (hint, it’s a bug: 19958239)
Update 30.05.2018 the solution is explained in this Doc: 2068066.1, thanks John)
The cleanup metadata is stored into the view DBA_AUDIT_MGMT_LAST_ARCH_TS. Its structure in 11g was:
|
1 2 3 4 5 6 |
SQL> desc dba_audit_mgmt_last_arch_ts Name Null? Type ----------------------------------------- -------- ---------------------------- AUDIT_TRAIL VARCHAR2(20) RAC_INSTANCE NOT NULL NUMBER LAST_ARCHIVE_TS TIMESTAMP(6) WITH TIME ZONE |
But in 12c, there are 2 new columns:
|
1 2 3 4 5 6 7 8 |
SQL> desc dba_audit_mgmt_last_arch_ts Name Null? Type ------------------------------------- -------- ---------------------------- AUDIT_TRAIL VARCHAR2(20) RAC_INSTANCE NOT NULL NUMBER LAST_ARCHIVE_TS TIMESTAMP(6) WITH TIME ZONE DATABASE_ID NOT NULL NUMBER CONTAINER_GUID NOT NULL VARCHAR2(33) |
When the database is upgraded from 11g to 12c, the two new columns are set to “0” by default.
|
1 2 3 4 5 6 |
SQL> select * from dba_audit_mgmt_last_arch_ts; AUDIT_TRAIL RAC_INSTANCE LAST_ARCHIVE_TS DATABASE_ID CONTAINER_GUID --------------------------- ------------ ------------------------------------ ----------- -------------------------------- STANDARD AUDIT TRAIL 0 04-FEB-17 05.01.10.000000 AM +00:00 0 00000000000000000000000000000000 OS AUDIT TRAIL 1 04-FEB-17 05.01.15.000000 AM +02:00 0 00000000000000000000000000000000 |
But when the procedure DBMS_AUDIT_MGMT.SET_LAST_ARCHIVE_TIMESTAMP is executed, the actual dbid is used, and new lines appear:
|
1 2 3 4 5 6 7 8 |
SQL> select * from dba_audit_mgmt_last_arch_ts; AUDIT_TRAIL RAC_INSTANCE LAST_ARCHIVE_TS DATABASE_ID CONTAINER_GUID --------------------------- ------------ ------------------------------------ ----------- -------------------------------- STANDARD AUDIT TRAIL 0 04-FEB-17 05.01.10.000000 AM +00:00 0 00000000000000000000000000000000 OS AUDIT TRAIL 1 04-FEB-17 05.01.15.000000 AM +02:00 0 00000000000000000000000000000000 STANDARD AUDIT TRAIL 0 27-MAR-18 12.29.55.000000 PM +00:00 2416611527 4A2962517EF2316FE0532296780AE383 OS AUDIT TRAIL 1 27-MAR-18 12.20.06.000000 PM +02:00 2416611527 4A2962517EF2316FE0532296780AE383 |
It is clear now that the DELETE statement is not constructed properly. It should get the LAST_ARCHIVE_TS of the actual DBID being purged… but it takes the other one.
According to my tests, it does not use neither the correct timestamp for the dbid, nor get the oldest timestamp: it uses instead the timestamp of the first record found by the clause “WHERE AUDIT_TRAIL=’STANDARD AUDIT TRAIL'”. It depends on the physical location of the row in the table! Clearly a big mess… (PS, not sure 100%, but this is what I suppose)
So, I have tried to modify the archive time for DBID 0:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
SQL> begin 2 dbms_audit_mgmt.set_last_archive_timestamp(audit_trail_type => DBMS_AUDIT_MGMT.AUDIT_TRAIL_AUD_STD 3 ,last_archive_time => SYSTIMESTAMP-31 4 ,database_id => 0 5 ,container_guid => '00000000000000000000000000000000'); 6 end; 7 8 / PL/SQL procedure successfully completed. SQL> select database_id, audit_trail, last_archive_ts from dba_audit_mgmt_last_arch_ts; DATABASE_ID AUDIT_TRAIL LAST_ARCHIVE_TS ----------- ----------------------------- ---------------------------------------- 0 STANDARD AUDIT TRAIL 27-MAR-18 12.37.22.000000 PM +00:00 0 OS AUDIT TRAIL 04-FEB-17 05.01.15.000000 AM +02:00 2416611527 STANDARD AUDIT TRAIL 27-MAR-18 12.29.55.000000 PM +00:00 2416611527 OS AUDIT TRAIL 27-MAR-18 12.20.06.000000 PM +02:00 |
Trying to execute the cleanup again, now leads to a better timestamp:
|
1 |
DELETE FROM SYS.AUD$ WHERE DBID = 2416611527 AND NTIMESTAMP# < to_timestamp('2018-03-27 12:37:22', 'YYYY-MM-DD HH24:MI:SS.FF') AND ROWNUM <= 140724603463440 |
I have then tried to play a little bit with the DBA_AUDIT_MGMT_LAST_ARCH_TS view (and the underlying table DAM_LAST_ARCH_TS$).
First, I’ve faked the DBID:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
SQL> update dba_audit_mgmt_last_arch_ts set database_id=2416611526 where database_id=0; 2 rows updated. SQL> commit; Commit complete. SQL> select database_id, audit_trail, last_archive_ts from DBA_AUDIT_MGMT_LAST_ARCH_TS; DATABASE_ID AUDIT_TRAIL LAST_ARCHIVE_TS ----------- ------------------------------------------------------------ --------------------------------------------------------------------------- 2416611526 STANDARD AUDIT TRAIL 27-MAR-18 12.37.22.000000 PM +00:00 2416611526 OS AUDIT TRAIL 04-FEB-17 05.01.15.000000 AM +02:00 2416611527 STANDARD AUDIT TRAIL 27-MAR-18 12.29.55.000000 PM +00:00 2416611527 OS AUDIT TRAIL 27-MAR-18 12.20.06.000000 PM +02:00 |
Then, I have tried to increase the retention timestamp (500 days):
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
SQL> begin 2 dbms_audit_mgmt.set_last_archive_timestamp(audit_trail_type => DBMS_AUDIT_MGMT.AUDIT_TRAIL_AUD_STD 3 ,last_archive_time => SYSTIMESTAMP-500 4 ,database_id => 2416611526 5 ,container_guid => '00000000000000000000000000000000'); 6 end; 7 / PL/SQL procedure successfully completed. SQL> select database_id, audit_trail, last_archive_ts from dba_audit_mgmt_last_arch_ts; DATABASE_ID AUDIT_TRAIL LAST_ARCHIVE_TS ----------- ------------------------------------------------------------ --------------------------------------------------------------------------- 2416611526 STANDARD AUDIT TRAIL 13-DEC-16 12.48.23.000000 PM +00:00 2416611526 OS AUDIT TRAIL 04-FEB-17 05.01.15.000000 AM +02:00 2416611527 STANDARD AUDIT TRAIL 27-MAR-18 12.29.55.000000 PM +00:00 2416611527 OS AUDIT TRAIL 27-MAR-18 12.20.06.000000 PM +02:00 |
Finally, I have tried to purge the audit trail with both DBIDs:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 |
SQL> begin 2 dbms_audit_mgmt.clean_audit_trail( 3 audit_trail_type => sys.dbms_audit_mgmt.AUDIT_TRAIL_AUD_STD, 4 database_id => 2416611526, 5 use_last_arch_timestamp => TRUE); 6 end; 7 / PL/SQL procedure successfully completed. Elapsed: 00:00:45.89 SQL> begin 2 dbms_audit_mgmt.clean_audit_trail( 3 audit_trail_type => sys.dbms_audit_mgmt.AUDIT_TRAIL_AUD_STD, 4 database_id => 2416611527, 5 use_last_arch_timestamp => TRUE); 6 end 7 ; 8 / PL/SQL procedure successfully completed. Elapsed: 00:00:34.72 |
As I expected, in both cases the the cleanup generated the delete with the timestamp of the fake DBID:
|
1 2 3 4 5 |
-- clean audit trail for dbid 2416611526 DELETE FROM SYS.AUD$ WHERE DBID = 2416611526 AND NTIMESTAMP# < to_timestamp('2016-12-13 12:48:23', 'YYYY-MM-DD HH24:MI:SS.FF') AND ROWNUM <= 140724603463440 -- clean audit trail for dbid 2416611527 DELETE FROM SYS.AUD$ WHERE DBID = 2416611527 AND NTIMESTAMP# < to_timestamp('2016-12-13 12:48:23', 'YYYY-MM-DD HH24:MI:SS.FF') AND ROWNUM <= 140724603463440 |
Is it possible to delete the unwanted records from the view DBA_AUDIT_MGMT_LAST_ARCH_TS?
Not only is possible, but I recommend it:
|
1 2 3 4 5 6 7 8 9 |
SQL> delete from dba_audit_mgmt_last_arch_ts where database_id=2416611526; 2 rows deleted. SQL> commit; Commit complete. SQL> |
Afterwards, the timestamp in the where condition is correct and remains correct after subsequent executions of DBMS_AUDIT_MGMT.SET_LAST_ARCHIVE_TIMESTAMP.
Conclusions, IMPORTANT FOR THE DATABASE OPERATIONS:
The upgrade causes the unwanted lines with DBID=0 in the DBA_AUDIT_MGMT_LAST_ARCH_TS view.
Moreover, any duplicate changes the DBID: any subsequent execution of DBMS_AUDIT_MGMT.SET_LAST_ARCHIVE_TIMESTAMP in the duplicated database will lead to additional lines in the view.
This is what I plan to do now:
- Whenever I upgrade from 11g to 12c, cleanup the data from DBA_AUDIT_MGMT_LAST_ARCH_TS and schedule the cleanup for DBID 0 as well
- Whenever I duplicate a database, I execute a DELETE (without clauses) from DBA_AUDIT_MGMT_LAST_ARCH_T and a truncate of the table SYS.AUD$ (it is a duplicate, after all!)
HTH
Latest posts by Ludovico (see all)
- New views in Oracle Data Guard 23c - January 3, 2024
- New in Data Guard 21c and 23c: Automatic preparation of the primary - December 22, 2023
- Does FLASHBACK QUERY work across incarnations or after a Data Guard failover? - December 13, 2023
Hi Ludovico,
thank you for your very clear explanation about this issue with old standard auditing cleaning process in 12cR2. I could recover a lot of space once the dbms_audit_mgmt.clean_audit_trail run. All space into was recover into the SYS.AUD$ segment, but the LOB segment related to the table, kept untouched. Based note Doc ID 1935169.1 (DBMS_AUDIT_MGMT does not release the space occupied by LOB segment ) this behavior is spected.
After cleaning SYS.AUD$ except the last 7 days, I run the segment advisor and shrink the SYS.AUD$ segment reducing the size to 300mb, all was successfully, except to release space into the LOB segment.
Do you know if there is some specific method to purge the LOG segment information older than 7 days ?
Thank you in advance
Adrian
Cleaning of FGA or Unified Audit Trail Records Not Working in 12C (Doc ID 2068066.1)
Hi John, thanks for the Doc ID. I was not able to find a note for this when I had my problem the first time.
I have updated the post.
Pingback: Blog Post: DBMS_AUDIT_MGMT.CLEAN_AUDIT_TRAIL not working on 12c? Here’s why…
Pingback: DBMS_AUDIT_MGMT.CLEAN_AUDIT_TRAIL not working on 12c? Here’s why… - Ludovico Caldara - Blogs - triBLOG