Pickleball spielen

There is a new auditing architecture in place with Oracle Database 12c, called Unified Auditing. Why would you want to use it? Because it has significantly less performance impact than the old approach. We buffer now audit records in the SGA and write them asynchronously to disk, that’s the trick:

Other benefits of the new approach are that we have now one centralized way (and one syntax also) to deal with all the various auditing features that have been introduced over time, like Fine Grained Auditing etc. But the key improvement in my opinion is the reduced performance impact, because that was often hurting customers in the past. Let’s see it in action! First, I will record a baseline without any auditing:

[oracle@uhesse ~]$ sqlplus / as sysdba

SQL*Plus: Release 12.1.0.2.0 Production on Fri Jul 31 08:54:32 2015

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


Connected to:
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
With the Partitioning, OLAP, Advanced Analytics and Real Application Testing options

SQL> select value from v$option where parameter='Unified Auditing';

VALUE
----------------------------------------------------------------
FALSE

SQL> @audit_baseline
Connected.

Table truncated.


Noaudit succeeded.


PL/SQL procedure successfully completed.

Connected.

PL/SQL procedure successfully completed.

Elapsed: 00:00:06.07
Connected.

PL/SQL procedure successfully completed.
SQL> host cat audit_baseline.sql
connect / as sysdba
truncate table aud$;
noaudit select on adam.sales;
exec dbms_workload_repository.create_snapshot

connect adam/adam
set timing on
declare v_product adam.sales.product%type;
begin
for i in 1..100000 loop
select product into v_product from adam.sales where id=i;
end loop;
end;
/
set timing off

connect / as sysdba
exec dbms_workload_repository.create_snapshot

So that is just 100k SELECT against a 600M MB table with an index on ID without auditing so far. Key sections of the AWR report for the baseline:

The most resource consuming SQL in that period was the AWR snapshot itself. Now let’s see how the old way to audit impacts performance here:

SQL>  show parameter audit_trail

NAME_COL_PLUS_SHOW_PARAM                 TYPE        VALUE_COL_PLUS_SHOW_PARAM
---------------------------------------- ----------- ----------------------------------------
audit_trail                              string      DB, EXTENDED
SQL> @oldaudit
Connected.

Table truncated.


Audit succeeded.


PL/SQL procedure successfully completed.

Connected.

PL/SQL procedure successfully completed.

Elapsed: 00:00:56.42
Connected.

PL/SQL procedure successfully completed.
SQL> host cat oldaudit.sql
connect / as sysdba
truncate table aud$;
audit select on adam.sales by access;
exec dbms_workload_repository.create_snapshot

connect adam/adam
set timing on
declare v_product adam.sales.product%type;
begin
for i in 1..100000 loop
select product into v_product from adam.sales where id=i;
end loop;
end;
/
set timing off

connect / as sysdba
exec dbms_workload_repository.create_snapshot

That was almost 10 times slower! The AWR report confirms that and shows why it is so much slower now:

It’s because of the 100k inserts into the audit trail, done synchronously to the SELECTs. The audit trail is showing them here:

SQL> select sql_text,sql_bind from dba_audit_trail where rownum<=10; 
SQL_TEXT                                           SQL_BIND 
-------------------------------------------------- ---------- 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):1 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):2 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):3 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):4 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):5 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):6 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):7 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):8 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(1):9 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1         #1(2):10 
10 rows selected. 
SQL> select count(*) from dba_audit_trail where sql_text like '%SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1%';

  COUNT(*)
----------
    100000

Now I will turn on Unified Auditing – that requires a relinking of the software while the database is down. Afterwards:

SQL> select value from v$option where parameter='Unified Auditing';

VALUE
----------------------------------------------------------------
TRUE

SQL> @newaudit
Connected.

Audit policy created.


Audit succeeded.


PL/SQL procedure successfully completed.

Connected.

PL/SQL procedure successfully completed.

Elapsed: 00:00:11.90
Connected.

PL/SQL procedure successfully completed.
SQL> host cat newaudit.sql
connect / as sysdba
create audit policy audsales actions select on adam.sales;
audit policy audsales;
exec dbms_workload_repository.create_snapshot

connect adam/adam
set timing on
declare v_product adam.sales.product%type;
begin
for i in 1..100000 loop
select product into v_product from adam.sales where id=i;
end loop;
end;
/
set timing off

connect / as sysdba
exec dbms_workload_repository.create_snapshot

That was still slower than the baseline, but much better than with the old method! Let’s see the AWR report for the last run:

Similar to the first (baseline) run, the snapshot is the most resource consuming SQL during the period. DB time as well as elapsed time are shorter by far than with the old audit architecture. The 100k SELECTs together with the bind variables have been captured here as well:

SQL> select sql_text,sql_binds from unified_audit_trail where rownum<=10; 
SQL_TEXT                                                     SQL_BINDS 
------------------------------------------------------------ ---------- 
ALTER DATABASE OPEN 
create audit policy audsales actions select on adam.sales 
audit policy audsales 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):1 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):2 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):3 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):4 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):5 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):6 
SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1                   #1(1):7 
10 rows selected. 
SQL> select count(*) from unified_audit_trail where sql_text like '%SELECT PRODUCT FROM ADAM.SALES WHERE ID=:B1%';

  COUNT(*)
----------
    100000

The first three lines above show that sys operations are also recorded in the same (Unified!) Audit Trail, by the way. There is much more to say and to learn about Unified Auditing of course, but this may give you a kind of motivation to evaluate it, especially if you have had performance issues in the past related to auditing. As always: Don’t believe it, test it! 🙂

 See me here in a video clip, explaining the above. Subscription to Oracle Learning Streams is free for OCP and OCE and included for 30 days after an Oracle University class.

A Practical Guide To #Oracle Database 12c Unified Auditing https://t.co/awCxVlGvFa Free for OCP, OCE and for 30 days after a class with us

— Uwe Hesse (@UweHesse) October 21, 2015