Unified Auditing – some insights
Oracle 12c Unified Auditing is a brand new feature in the latest Oracle version which consolidates database level auditing records into a single location. DBAs can access the audit information from the view UNIFIED_AUDIT_TRAIL for all kind audit records, and they are
SQL> select distinct COMPONENT from all_unified_audit_actions; COMPONENT ---------------------------------------------------------------- Direct path API RMAN_AUDIT Database Vault XS Label Security Datapump Standard FineGrainedAudit 8 rows selected.
UNIFIED_AUDIT_TRAIL is a view owned by SYS and a public synonym pointing to this view.
SQL> select owner,object_type from dba_objects where object_name='UNIFIED_AUDIT_TRAIL'; OWNER OBJECT_TYPE ---------- ------------------------------ SYS VIEW PUBLIC SYNONYM
Any database user who got ADUIT_ADMIN and AUDIT_VIEWER roles can administer and view the audit records respectively. Oracle separated the AUDITOR role from the traditional DBA/ SYSDBA roles so that and independent database auditor can operate outside the DBA group. To harden the security, no DBA or SYSDBA users can UPDATE or DELETE the audit records outside DBMS_AUDIT_MGMT.
Audit records are physically stored in AUDSYS schema along with other supporting indexes and BLOBS.
SSQL> select owner,object_type,object_name from dba_objects where owner='AUDSYS'; OWNER OBJECT_TYPE OBJECT_NAME ---------- ------------------------------ ------------------------------ AUDSYS INDEX CLI_LOB$7e10621c$1$1 AUDSYS INDEX PARTITION CLI_LOB$7e10621c$1$1 AUDSYS INDEX CLI_TIME$7e10621c$1$1 AUDSYS INDEX PARTITION CLI_TIME$7e10621c$1$1 AUDSYS LOB SYS_LOB0000091761C00014$$ AUDSYS LOB PARTITION SYS_LOB0000091761C00014$$ AUDSYS INDEX SYS_IL0000091761C00014$$ AUDSYS INDEX PARTITION SYS_IL0000091761C00014$$ AUDSYS INDEX CLI_SCN$7e10621c$1$1 AUDSYS INDEX PARTITION CLI_SCN$7e10621c$1$1 AUDSYS TABLE PARTITION CLI_SWP$7e10621c$1$1 AUDSYS TABLE CLI_SWP$7e10621c$1$1 12 rows selected.
You can see a table CLI_SWP$7e10621c$1$1 and the audit records are writing to this table and UNIFIED_AUDIT_TRAIL must be a view built on this table – just an assumption as the view is getting the records from the audit base table. Let us confirm that assumption by checking the execution plan for UNIFIED_AUDIT_TRAIL.
--------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | TQ |IN-OUT| PQ Distrib |
--------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 11738 | 1123K| 6 (34)| 00:00:01 | | | |
|* 1 | HASH JOIN RIGHT OUTER | | 11738 | 1123K| 6 (34)| 00:00:01 | | | |
| 2 | INDEX FAST FULL SCAN | I_STMT_AUDIT_OPTION_MAP | 308 | 1232 | 2 (0)| 00:00:01 | | | |
| 3 | NESTED LOOPS | | 11738 | 1077K| 4 (50)| 00:00:01 | | | |
|* 4 | HASH JOIN RIGHT OUTER| | 11738 | 997K| 4 (50)| 00:00:01 | | | |
| 5 | INDEX FAST FULL SCAN| I_SYSTEM_PRIVILEGE_MAP | 237 | 1185 | 2 (0)| 00:00:01 | | | |
| 6 | PX COORDINATOR | | | | | | | | |
| 7 | PX SEND QC (RANDOM)| :TQ10000 | 11738 | 229K| 2 (100)| 00:00:01 | Q1,00 | P->S | QC (RAND) |
|* 8 | VIEW | GV$UNIFIED_AUDIT_TRAIL | | | | | Q1,00 | PCWP | |
|* 9 | FIXED TABLE FULL | X$UNIFIED_AUDIT_TRAIL | 11738 | 229K| 2 (100)| 00:00:01 | Q1,00 | PCWP | |
|* 10 | INDEX UNIQUE SCAN | I_UNIFIED_AUDIT_ACTIONS | 1 | 7 | 0 (0)| 00:00:01 | | | |
--------------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - access("AUDIT_OPTION"="AOM"."OPTION#"(+))
4 - access("SPX"."PRIVILEGE"(+)=(-"SYSTEM_PRIVILEGE"))
8 - filter("CON_ID"=0 OR "CON_ID"=1)
9 - filter("CON_ID"=0 OR "CON_ID"=1)
10 - access("AUDIT_TYPE"="ACT"."TYPE" AND "ACTION"="ACT"."ACTION")
Note
-----
- statement not queuable: gv$ statement
Statistics
----------------------------------------------------------
134589 recursive calls
0 db block gets
300896 consistent gets
0 physical reads
0 redo size
2057935 bytes sent via SQL*Net to client
85625 bytes received via SQL*Net from client
7736 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
116016 rows processed
That is bit interesting – the base table for UNIFIED_AUDIT_TRAIL is not the actual audit table in the SYSAUD schema, rather the records are coming from an X$ table known as X$UNIFIED_AUDIT_TRAIL and that is confusing. Moreover, the x$ fixed table is owned by SYS user, not in SYSAUD schema! You can see the fixed table X$UNIFIED_AUDIT_TRAIL existing in the V$FIXED_TABLE view.
SQL> select * from v$fixed_table where name='X$UNIFIED_AUDIT_TRAIL'; NAME OBJECT_ID TYPE TABLE_NUM CON_ID ------------------------------ ---------- ----- ---------- ---------- X$UNIFIED_AUDIT_TRAIL 4294953277 TABLE 641 0
So, there is some relation existing between the fixed table X$UNIFIED_AUDIT_TRAIL and CLI_SWP$7e10621c$1$1, the physical table where the actual data is existing. Moreover, every X$ table is a non-physical volatile table interfacing a memory structure and not really suitable to store the audit records. Trace 10046 should tell us more inside stories and relation between X$UNIFIED_AUDIT_TRAIL and CLI_SWP$7e10621c$1$1.
From the 10046 tracing came to a conclusion – the reading the audit records happening in two phases.
Phase 1: Oracle read the complete base audit table and populates the X$UNIFIED_AUDIT_TRAIL table for that container.
FETCH #140085662005752:c=0,e=28,p=0,cr=4,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120329 FETCH #140085662005752:c=0,e=113,p=0,cr=2,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120480 FETCH #140085662005752:c=0,e=25,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120548 FETCH #140085662005752:c=0,e=19,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120601 FETCH #140085662005752:c=0,e=18,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120651 FETCH #140085662005752:c=999,e=55,p=0,cr=2,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120736 FETCH #140085662005752:c=0,e=24,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120806 FETCH #140085662005752:c=0,e=21,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120860 FETCH #140085662005752:c=0,e=24,p=0,cr=4,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120916 FETCH #140085662005752:c=0,e=18,p=0,cr=2,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850120966 FETCH #140085662005752:c=0,e=16,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850121014 FETCH #140085662005752:c=0,e=17,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850121059 FETCH #140085662005752:c=0,e=16,p=0,cr=2,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850121104 FETCH #140085662005752:c=0,e=21,p=0,cr=4,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850121157 FETCH #140085662005752:c=0,e=23,p=0,cr=4,cu=0,mis=0,r=1,dep=2,og=1,plh=1405023807,tim=10748850121212 STAT #140085662005752 id=1 cnt=102 pid=0 pos=1 obj=0 op='PARTITION RANGE SINGLE PARTITION: KEY 1 (cr=286 pr=1 pw=0 time=66 us cost=496 size=70729009 card=32579)' STAT #140085662005752 id=2 cnt=102 pid=1 pos=1 obj=91761 op='TABLE ACCESS BY LOCAL INDEX ROWID CLI_SWP$7e10621c$1$1 PARTITION: KEY 1 (cr=286 pr=1 pw=0 time=55 us cost=496 size=70729009 card=32579)' STAT #140085662005752 id=3 cnt=169 pid=2 pos=1 obj=91771 op='INDEX RANGE SCAN CLI_LOB$7e10621c$1$1 PARTITION: KEY 1 (cr=103 pr=1 pw=0 time=462 us cost=496 size=0 card=50122)' CLOSE #140085662005752:c=0,e=80,dep=2,type=1,tim=10748850121429
Phase : 2 – User get the audit records from the X$UNIFIED_AUDIT_TRAIL base table, need not worry about the rest of the containers audit data as it is filtered at the first place.
EXEC #140085626601992:c=0,e=46,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=1,plh=1999586355,tim=10748918362622 FETCH #140085626601992:c=0,e=18,p=0,cr=1,cu=0,mis=0,r=1,dep=2,og=1,plh=1999586355,tim=10748918362650 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 25 p1=0 p2=0 p3=0 obj#=91764 tim=10748918362746 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 7 p1=0 p2=0 p3=0 obj#=91764 tim=10748918363179 WAIT #140085668747360: nam='PX Deq Credit: send blkd' ela= 435 sleeptime/senderid=268632063 passes=1 qref=7974696744 obj#=91764 tim=10748918363179 WAIT #140085668747360: nam='Disk file operations I/O' ela= 246 FileOperation=2 fileno=0 filetype=36 obj#=91764 tim=10748918364034 WAIT #140085668747360: nam='Disk file operations I/O' ela= 1115 FileOperation=8 fileno=1 filetype=36 obj#=91764 tim=10748918365176 WAIT #140085668747360: nam='Disk file operations I/O' ela= 1346 FileOperation=5 fileno=0 filetype=36 obj#=91764 tim=10748918366577 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 31 p1=0 p2=0 p3=0 obj#=91764 tim=10748918366739 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 56 p1=0 p2=0 p3=0 obj#=91764 tim=10748918371873 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 9 p1=0 p2=0 p3=0 obj#=91764 tim=10748918371951 WAIT #140085668747360: nam='PX Deq Credit: send blkd' ela= 5155 sleeptime/senderid=268632063 passes=1 qref=7974696744 obj#=91764 tim=10748918371951 EXEC #140085668747360:c=22873523,e=158435095,p=32962,cr=231162,cu=889,mis=0,r=0,dep=1,og=1,plh=4119967587,tim=10748918372017 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 9 p1=0 p2=0 p3=0 obj#=91764 tim=10748918372133 WAIT #140085668747360: nam='PX Deq: reap credit' ela= 15 p1=0 p2=0 p3=0 obj#=91764 tim=10748918380111 WAIT #140085668747360: nam='PX Deq: Execution Msg' ela= 8930 sleeptime/senderid=268632063 passes=2 p3=7974696744 obj#=91764 tim=10748918381073 STAT #140085668747360 id=1 cnt=0 pid=0 pos=1 obj=0 op='HASH JOIN RIGHT OUTER (cr=0 pr=0 pw=0 time=0 us cost=8 size=448192054 card=11738)' STAT #140085668747360 id=2 cnt=0 pid=1 pos=1 obj=464 op='INDEX FAST FULL SCAN I_STMT_AUDIT_OPTION_MAP (cr=0 pr=0 pw=0 time=0 us cost=2 size=7084 card=308)' STAT #140085668747360 id=3 cnt=0 pid=1 pos=2 obj=0 op='HASH JOIN RIGHT OUTER (cr=0 pr=0 pw=0 time=0 us cost=6 size=447922080 card=11738)' STAT #140085668747360 id=4 cnt=0 pid=3 pos=1 obj=455 op='INDEX FAST FULL SCAN I_SYSTEM_PRIVILEGE_MAP (cr=0 pr=0 pw=0 time=0 us cost=2 size=5925 card=237)' STAT #140085668747360 id=5 cnt=0 pid=3 pos=2 obj=0 op='HASH JOIN (cr=0 pr=0 pw=0 time=0 us cost=4 size=447628630 card=11738)' STAT #140085668747360 id=6 cnt=0 pid=5 pos=1 obj=4598 op='TABLE ACCESS FULL ALL_UNIFIED_AUDIT_ACTIONS (cr=0 pr=0 pw=0 time=0 us cost=2 size=8711 card=281)' STAT #140085668747360 id=7 cnt=0 pid=5 pos=2 obj=0 op='PX COORDINATOR (cr=0 pr=0 pw=0 time=0 us)' STAT #140085668747360 id=8 cnt=0 pid=7 pos=1 obj=0 op='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us cost=2 size=27995130 card=11738)' STAT #140085668747360 id=9 cnt=99506 pid=8 pos=1 obj=4294953278 op='VIEW GV$UNIFIED_AUDIT_TRAIL (cr=231043 pr=32962 pw=0 time=108383889 us)' STAT #140085668747360 id=10 cnt=99506 pid=9 pos=1 obj=0 op='FIXED TABLE FULL X$UNIFIED_AUDIT_TRAIL (cr=231043 pr=32962 pw=0 time=108237708 us cost=2 size=27995130 card=11738)'
So, that is where the fixed table X$UNIFIED_AUDIT_TRAIL come into play and this is not really going to be easy. Look at the below SELECT –
SQL> select * from unified_audit_trail; 158836 rows selected. Elapsed: 00:01:16.35
I just got 158836 audit records and it took 76.35 seconds! Where the time is spent? Look at the recursive calls. I believe, these are DB calls for populating the fixed table, X$UNIFIED_AUDIT_TRAIL from the SYSAUD physical table where the consolidated audit records are located. Compared to traditional tables, your audit table access will be much slow.
Statistics
----------------------------------------------------------
194858 recursive calls
2285 db block gets
398738 consistent gets
46457 physical reads
140 redo size
84053638 bytes sent via SQL*Net to client
35188183 bytes received via SQL*Net from client
292940 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
158836 rows processed
Currently, I have only few days of STANDARD audit records for a single PDB. It will be interesting to see, what will be response time and memory usage if I am hosting few years of audit records for security compliance and for a number of PDBs. One needs to do test the real impact before enabling the unified auditing and retaining the records for a longer period.
Note: These are my own opinions and research and can be wrong. Do your research before implementing and I will not accept any liabilities or damages.
Thomas Saviour's Blog 
good article….
Great job! Very clear and succinct!