By Franck Pachot

.
When you want to empty a table you have two methods: delete and truncate. If, for any reason (see previous post) the Unified Audit Trail has become too big, you cannot directly delete or truncate the table. You must call the dbms_audit_mgmt.clean_audit_trail. But then you want to know if it will do slow deletes or quick truncates. Let’s trace it.

I have filled my Unified Audit Trail with hundred of thousands failed logins:

SQL> select unified_audit_policies,action_name,count(*) from unified_audit_trail group by unified_audit_policies,action_name;
 
UNIFIED_AUDIT_POLICIES                   ACTION_NAME            COUNT(*)
---------------------------------------- -------------------- ----------
                                         EXECUTE                       2
ORA_LOGON_FAILURES                       LOGON                    255799

We have two methods to purge: purge records older than a timestamp or purge all.

Purge old

Auditing is different than logging. It’s a security feature. The goal is not to keep only recent information by specifying a retention. The goal is to read, process and archive the records, and then set a timestamp to the high water mark that has been processed. Then a background job will delete what is before this timestamp.

I set the timestamp to 6 hours before now

SQL> exec dbms_audit_mgmt.set_last_archive_timestamp(audit_trail_type=>dbms_audit_mgmt.audit_trail_unified
,last_archive_time=>sysdate-6/24);
PL/SQL procedure successfully completed.

And call the clean procedure:

SQL> exec dbms_audit_mgmt.clean_audit_trail(audit_trail_type=>dbms_audit_mgmt.audit_trail_unified
,use_last_arch_timestamp=TRUE);
PL/SQL procedure successfully completed.

This was fast but let’s look at the tkprof. Besides some select, I see a delete on the CLI_SWP$ table that stores the Unified Audit Trail in Secure File LOBs

delete from "CLI_SWP$2f516430$1$1" partition("HIGH_PART")
where
 max_time < :1
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.47       1.82         20        650      47548        6279
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.47       1.82         20        650      47548        6279
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 7     (recursive depth: 1)
Number of plan statistics captured: 1
 
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  CLI_SWP$2f516430$1$1 (cr=650 pr=20 pw=0 time=1827790 us)
      6279       6279       6279   PARTITION RANGE SINGLE PARTITION: 1 1 (cr=248 pr=0 pw=0 time=15469 us cost=5 size=18020 card=530)
      6279       6279       6279    TABLE ACCESS FULL CLI_SWP$2f516430$1$1 PARTITION: 1 1 (cr=248 pr=0 pw=0 time=10068 us cost=5 size=18020 card=530)

I will not go into the detail there. This delete may be optimized (120000 audit trail records were actually deleted here behind those 6000 rows. This table is partitioned, and we can expect that old partitions are truncated but there are many bugs with that. On lot of environments we see all rows in HIGH_PART.
This is improved in 12cR2 and will be the subject of a future post. I you have a huge audit trail to purge, then conventional delete is not optimal.

Purge all

I have still lot of rows remaining.

SQL> select unified_audit_policies,action_name,count(*) from unified_audit_trail group by unified_audit_policies,action_name;
 
UNIFIED_AUDIT_POLICIES                   ACTION_NAME            COUNT(*)
---------------------------------------- -------------------- ----------
                                         EXECUTE                       4
ORA_LOGON_FAILURES                       LOGON                    136149

When purging all without setting a timestamp, I expect a truncate which is faster than deletes. Let’s try it and trace it.

SQL> exec dbms_audit_mgmt.clean_audit_trail(audit_trail_type=>dbms_audit_mgmt.audit_trail_unified
,use_last_arch_timestamp=FALSE);
PL/SQL procedure successfully completed.

First, there seem to be an internal log acquired:

SELECT LOCKID FROM DBMS_LOCK_ALLOCATED WHERE NAME = :B1 FOR UPDATE
UPDATE DBMS_LOCK_ALLOCATED SET EXPIRATION = SYSDATE + (:B1 /86400) WHERE ROWID = :B2

Then a partition split:

alter table "CLI_SWP$2f516430$1$1" split partition high_part at (3013381) into (partition "PART_6",  partition high_part lob(log_piece) store as securefile (cache logging    tablespace SYSAUX) tablespace "SYSAUX")

The split point is the current timestamp SCN:

SQL> select scn_to_timestamp(3013381) from dual;
 
SCN_TO_TIMESTAMP(3013381)
---------------------------------------------------------------------------
02-MAR-17 05.59.06.000000000 PM

This is the time when I’ve run the purge and this is probably used to ‘truncate’ all previous partition but keep the on-going one.

Then , there is no TRUNCATE in the trace, but something similar: some segments are dropped:

delete from seg$
where
 ts#=:1 and file#=:2 and block#=:3
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      6      0.00       0.00          0         18         12           6
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7      0.00       0.00          0         18         12           6

There is finally a delete, but with no rows to delete as the rows were in the dropped segments:

delete from "CLI_SWP$2f516430$1$1" partition("HIGH_PART")
where
 max_time < :1
 
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          3          0           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          3          0           0
 
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 7     (recursive depth: 1)
Number of plan statistics captured: 1
 
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  DELETE  CLI_SWP$2f516430$1$1 (cr=3 pr=0 pw=0 time=61 us)
         0          0          0   PARTITION RANGE SINGLE PARTITION: 1 1 (cr=3 pr=0 pw=0 time=57 us cost=5 size=2310 card=33)
         0          0          0    TABLE ACCESS FULL CLI_SWP$2f516430$1$1 PARTITION: 1 1 (cr=3 pr=0 pw=0 time=48 us cost=5 size=2310 card=33)

So what?

Cleaning the Unified Audit Trail is done with internal statements but looks like a delete when use_last_arch_timestamp=TRUE or a truncate when use_last_arch_timestamp=FALSE. This means that we can use this procedure when AUDSYS has grown too much. However, there are a few bug with this internal table, partitioned even when partitioning is not allowed. The implementation has changed in 12.2 so the next blog post will show the same test on 12cR2.