Getting the current SQL statement from SYS_CONTEXT using Fine Grained Auditing

The stand-off between Apple and the FBI has moved on. In essence both sides have taken it in turns to refuse to tell each other how to hack an iPhone.

Something else that tends to tell little or nothing in the face of repeated interrogation is SYS_CONTEXT(‘userenv’, ‘current_sql’).
If you’re fortunate enough to be running on Enterprise Edition however, a Fine Grained Auditing Policy will loosen it’s tongue.

Consider the following scenario.
You’ve recently got a job as a database specialist with Spectre.
They’ve been expanding their IT department recently as the result of their “Global Surveillance Initiative”.

There’s not much of a view from your desk as there are no windows in the hollowed out volcano that serves as the Company’s HQ.
The company is using Oracle 12c Enterprise Edition.

Everything seems to be going along nicely until you suddenly get a “request” from the Head of Audit, a Mr Goldfinger.
The requirement is that any changes to employee data in the HR system are recorded, together with the statement executed to change each record.
Reading between the lines, you suspect that Mr White – head of HR – is not entirely trusted by the hierarchy.

Whilst journalling triggers are common enough, capturing the actual SQL used to make DML changes is a bit more of a challenge.
Explaining this to Mr Goldfinger is unlikely to be a career-enhancing move. You’re going to have to be a bit creative if you want to avoid the dreaded “Exit Interview” (followed by a visit to the Piranha tank).

First of all though….

Fine Grained Auditing Configuration

You need to do a quick check to make sure that Fine Grained Auditing is available and configured in the way you would expect.

Access to Fine Grained Auditing

FGA is a feature of Oracle Enterprise Edition.
If you were working on any other edition of the database, Oracle would tell you that FGA is not enabled. For example, running the following on Oracle Express Edition 11g…

begin
    dbms_fga.add_policy
    (
        object_schema => 'HR',
        object_name => 'DEPARTMENTS',
        policy_name => 'WATCHING YOU',
        audit_condition => null,
        statement_types => 'INSERT, UPDATE, DELETE'
    );
end;
/

… will result in the Oracle Database telling you your fish-food …

ERROR at line 1:
ORA-00439: feature not enabled: Fine-grained Auditing
ORA-06512: at "SYS.DBMS_FGA", line 20
ORA-06512: at line 2

You can avoid this embarrassment simply by checking what edition of Oracle you’re running :

select banner
from v$version
/

In the case of Oracle 12c, you’ll get :

BANNER
--------------------------------------------------------------------------------
Oracle Database 12c Enterprise Edition Release 12.1.0.2.0 - 64bit Production
PL/SQL Release 12.1.0.2.0 - Production
CORE	12.1.0.2.0	Production
TNS for Linux: Version 12.1.0.2.0 - Production
NLSRTL Version 12.1.0.2.0 - Production

If you don’t happen to work for a worldwide crime syndicate and/or don’t have access to an Enterprise Edition database, you can still have a play around by means of a Developer Day Virtual Box image.

Unified Auditing

The other thing you need to check is just where audit records are going to be written to. This is not so much a requirement for the solution being implemented here, but it is relevant to some of the examples that follow.

By default, unified auditing is not implemented in 12c and you can confirm this by running :

select value
from v$option
where parameter = 'Unified Auditing'
/

If the query returns FALSE, then Unified Auditing has not been enabled.
Otherwise, it’s probably worth taking a look at the documentation to see how this affects auditing behaviour in the database.

Initialization Parameters

Assuming Unified Auditing has not been configured, the location of the audit records will be dictated by the AUDIT_TRAIL initialization parameter. You can check this value as follows :

select value
from v$parameter
where name = 'audit_trail'
/

If the value is set to DB, or DB, EXTENDED then any FGA policies should write to the tables mentioned below.

Now to take a closer look at FGA…

How long before SYS_CONTEXT cracks ?

To test exactly when you will be able to retrieve the DML statement you’re interested in, you can knock up a quick test.

First, you need a table to audit against for testing purposes :

create table trigger_messages
(
    message varchar2(4000)
)
/

Next, a simple procedure to insert a record :

create or replace procedure add_message( i_msg in trigger_messages.message%type)
is
begin
    insert into trigger_messages(message) values( i_msg);
end;
/

Now for a DML trigger on the table :

create or replace trigger trg_msg
    for insert or update or delete 
    on trigger_messages
    compound trigger
    
    l_action varchar2(10);
    before statement is
    begin
        l_action := case when inserting then 'INSERT' when updating then 'UPDATE' else 'DELETE' end;
        dbms_output.put_line('Before Statement '||l_action);
        dbms_output.put_line( nvl( sys_context('userenv', 'current_sql'), 'My lips are sealed'));
    end before statement;
    
    before each row is
    begin
        dbms_output.put_line('Before Row '||l_action);
        dbms_output.put_line( nvl( sys_context('userenv', 'current_sql'), 'My lips are sealed'));
    end before each row;
    
    after each row is
    begin
        dbms_output.put_line('After Row '||l_action);
        dbms_output.put_line( nvl( sys_context('userenv', 'current_sql'), 'My lips are sealed'));
    end after each row;
    
    after statement is
    begin
        dbms_output.put_line('After Statement '||l_action);
        dbms_output.put_line( nvl( sys_context('userenv', 'current_sql'), 'My lips are sealed'));
    end after statement;
end trg_msg;
/

Next up, you need a procedure to serve as a handler for a Fine Grained Auditing event. The reason for this will become apparent when we run the test. Note that the signature for an FGA handler procedure is mandated :

create or replace procedure trg_msg_fga
(
    object_schema varchar2,
    object_name varchar2,
    policy_name varchar2
)
is
begin
    dbms_output.put_line('FGA Policy');
    dbms_output.put_line(sys_context('userenv', 'current_sql'));
    dbms_output.put_line(sys_context('userenv', 'current_bind'));
    dbms_output.put_line(sys_context('userenv', 'current_sql_length'));
end;
/

Now all that’s left to do is to create an FGA policy on the table :

begin
    dbms_fga.add_policy
    (
        object_schema => 'MIKE',
        object_name => 'TRIGGER_MESSAGES',
        policy_name => 'FIRING_ORDER',
        statement_types => 'INSERT, UPDATE, DELETE',
        handler_schema => 'MIKE',
        handler_module => 'TRG_MSG_FGA'
    );
end;
/

You can confirm that the policy has been created successfully and is enabled by querying DBA_AUDIT_POLICIES…

select object_schema, object_name, enabled,
    sel, ins, upd, del
from dba_audit_policies
where policy_owner = user
and policy_name = 'FIRING_ORDER'
/

OBJECT_SCHEMA	OBJECT_NAME	     ENABLED	SEL   INS   UPD   DEL
--------------- -------------------- ---------- ----- ----- ----- -----
MIKE		TRIGGER_MESSAGES     YES	NO    YES   YES   YES

Now you’re ready to test…

set serveroutput on size unlimited

begin 
    add_message('Spectre - at the cutting-edge of laser technology');
end;
/

update trigger_messages set message = 'Spectre - coming to a browser near you'
/

delete from trigger_messages
/

The results are quite interesting…

Before Statement INSERT
My lips are sealed
Before Row INSERT
My lips are sealed
FGA Policy
INSERT INTO TRIGGER_MESSAGES(MESSAGE) VALUES( :B1 )
#1(49):Spectre - at the cutting-edge of laser technology
51
After Row INSERT
My lips are sealed
After Statement INSERT
My lips are sealed

PL/SQL procedure successfully completed.

Before Statement UPDATE
My lips are sealed
Before Row UPDATE
My lips are sealed
FGA Policy
update trigger_messages set message = 'Spectre - coming to a browser near you'
78
After Row UPDATE
My lips are sealed
After Statement UPDATE
My lips are sealed

1 row updated.

Before Statement DELETE
My lips are sealed
Before Row DELETE
My lips are sealed
After Row DELETE
My lips are sealed
FGA Policy
delete from trigger_messages
28
After Statement DELETE
My lips are sealed

1 row deleted.

From this you conclude that :

  • sys_context is only populated with the current statement inside the fga handler procedure
  • the handler procedure is invoked prior to the after row event for inserts and updates, but not for deletes

At this point, you consider that it might just be simpler to interrogate the DBA_FGA_AUDIT_TRAIL view, which has also captured the DML statements we’ve just run :

select sql_text
from dba_fga_audit_trail
where policy_name = 'FIRING_ORDER'
order by timestamp
/  

SQL_TEXT
----------------------------------------------------------------------------------------------------------------------------------
INSERT INTO TRIGGER_MESSAGES(MESSAGE) VALUES( :B1 )
update trigger_messages set message = 'Spectre - coming to a browser near you'
delete from trigger_messages

Note – the bind values for the procedure call can be found in the SQL_BIND column of this view.

However, it’s worth noting that we haven’t actually commited the test transaction yet these records are still present.
They will remain there, even if the transaction is rolled back.

In the end, you decide that the best approach is a journalling trigger…

The Unnecessarily Slow Dipping Mechanism – the DML trigger

Due to the nature of the organization, Spectre doesn’t have employees. It has associates. This is reflected in the table that you need to audit :

create table associates
(
    emp_id number,
    emp_name varchar2(100),
    job_title varchar2(30)
)
/

The table to hold the audit trail will probably look something like this :

create table assoc_audit
(
    action varchar2(6),
    changed_by varchar2(30),
    change_ts timestamp,
    emp_id number,
    emp_name varchar2(100),
    job_title varchar2(30),
    statement varchar2(4000),
    binds varchar2(4000)
)
/

It’s worth pausing at this point to note that SYS_CONTEXT can report up to 32k of a statement.
It does this by splitting the statement into eight 4k chunks, available in the USERENV context variables CURRENT_SQL, CURRENT_SQL1…CURRENT_SQL7.
It also provides the length of the statement it currently holds in the CURRENT_SQL_LENGTH variable.
Therefore, you may consider having a 32k varchar statement column in the audit table ( if this is enabled on your database), or even a column for the contents of each of these variables.
For the sake of simplicity, plus the fact that none of the examples here are very large, you decide to stick with just the one 4k varchar column to hold the statement.

There’s a procedure for adding new records to the table :

create or replace procedure add_associate
(
    i_emp_id in associates.emp_id%type,
    i_name in associates.emp_name%type,
    i_job_title in associates.job_title%type
)
is
begin
    insert into associates( emp_id, emp_name, job_title)
    values( i_emp_id, i_name, i_job_title);
end;
/
    

In the real world this would probably be in a package, but hey, you’re working for Spectre.

Now we need a handler for the FGA policy that we’re going to implement. In order for the context values that are captured to be accessible to the trigger, this handler is going to be part of a package which includes a couple of package variables :

create or replace package assoc_fga_handler
as

    g_statement varchar2(4000);
    g_binds varchar2(4000);
    
    -- The procedure to be invoked by the FGA policy.
    -- Note that the signature for this procedure is mandatory
    procedure set_statement
    (
        object_schema varchar2,
        object_name varchar2,
        policy_name varchar2
    );
end assoc_fga_handler;
/

create or replace package body assoc_fga_handler
as

    procedure set_statement
    (
        object_schema varchar2,
        object_name varchar2,
        policy_name varchar2
    )
    is
    begin
        g_statement := sys_context('userenv', 'current_sql');
        g_binds := sys_context('userenv', 'current_bind');
    end set_statement;
end assoc_fga_handler;
/

Now for the trigger. You may notice some compromises here …

create or replace trigger assoc_aud
    for insert or update or delete on associates
    compound trigger

    type typ_audit is table of assoc_audit%rowtype index by pls_integer;
    tbl_audit typ_audit;
    l_idx pls_integer := 0;
    
    after each row is
    begin
        l_idx := tbl_audit.count + 1;
        tbl_audit(l_idx).action := case when inserting then 'INSERT' when updating then 'UPDATE' else 'DELETE' end;
        tbl_audit(l_idx).changed_by := user;
        tbl_audit(l_idx).change_ts := systimestamp;
        tbl_audit(l_idx).emp_id := case when inserting then :new.emp_id else :old.emp_id end;
        tbl_audit(l_idx).emp_name := case when inserting then :new.emp_name else :old.emp_name end;
        tbl_audit(l_idx).job_title := case when inserting then :new.job_title else :old.job_title end;
    end after each row;
    
    after statement is
    begin
        for i in 1..tbl_audit.count loop
            tbl_audit(i).statement := assoc_fga_handler.g_statement;
            tbl_audit(i).binds := assoc_fga_handler.g_binds;
        end loop;
        forall j in 1..tbl_audit.count
            insert into assoc_audit values tbl_audit(j);
        -- cleardown the array
        tbl_audit.delete;    
    end after statement;
end assoc_aud;
/

Due to the fact that the FGA policy is not fired until after an AFTER ROW trigger for a DELETE, we are only guaranteed to capture the CURRENT_SQL value in an AFTER STATEMENT trigger.
The upshot is that we’re left with a PL/SQL array which is not constrained by a LIMIT clause. In these circumstances it’s not too much of an issue, Spectre has quite a small number of employees…er…associates, so you’re not likely to end up with an array large enough to cause memory issues.
On a potentially larger volume of records you may well consider splitting the INSERT and UPDATE portions of the trigger so that you can limit the size of the arrays generated by these operations. For DELETEs however, it appears that we may well be stuck with this approach.
On a not entirely unrelated subject, Jeff Kemp has an interesting method of speeding up Journalling Triggers.

All that remains is for the FGA policy….

begin
    dbms_fga.add_policy
    (
        object_schema => 'MIKE',
        object_name => 'ASSOCIATES',
        policy_name => 'ASSOCIATES_DML',
        statement_types => 'INSERT, UPDATE, DELETE',
        handler_schema => 'MIKE',
        handler_module => 'ASSOC_FGA_HANDLER.SET_STATEMENT'
    );
end;
/

…and now you can test…

set serveroutput on size unlimited
--
-- Cleardown the tables before running the test
--
truncate table assoc_audit
/

truncate table associates
/

begin
    add_associate(1, 'Odd Job', 'HENCHMAN');
    add_associate(2, 'Jaws', 'HENCHMAN');
    add_associate(3, 'Mayday', 'HENCHWOMAN');
    add_associate(4, 'Ernst Stavro Blofeld', 'CRIMINAL MASTERMIND');
    add_associate(5, 'Emilio Largo', 'Deputy Evil Genius');
    
end;
/

insert into associates( emp_id, emp_name, job_title)
values(6, 'Hans', 'Bodyguard and Piranha keeper')
/

commit;

update associates
set job_title = 'VALET'
where emp_id = 1
/
commit;


delete from associates
where emp_id = 1
/

commit;

-- Spectre is an Equal Opportunities Employer...and I need a statement
-- affecting multiple rows to test so...
update associates
set job_title = 'HENCHPERSON'
where job_title in ('HENCHMAN', 'HENCHWOMAN')
/

commit;

It is with a sense of relief that, when you check the audit table after running this you find …

select action, emp_name, 
    statement, binds
from assoc_audit
order by change_ts
/

ACTION EMP_NAME 	    STATEMENT							 BINDS
------ -------------------- ------------------------------------------------------------ ----------------------------------------
INSERT Odd Job		    INSERT INTO ASSOCIATES( EMP_ID, EMP_NAME, JOB_TITLE) VALUES(  #1(1):1 #2(7):Odd Job #3(8):HENCHMAN
			     :B3 , :B2 , :B1 )

INSERT Jaws		    INSERT INTO ASSOCIATES( EMP_ID, EMP_NAME, JOB_TITLE) VALUES(  #1(1):2 #2(4):Jaws #3(8):HENCHMAN
			     :B3 , :B2 , :B1 )

INSERT Mayday		    INSERT INTO ASSOCIATES( EMP_ID, EMP_NAME, JOB_TITLE) VALUES(  #1(1):3 #2(6):Mayday #3(10):HENCHWOMAN
			     :B3 , :B2 , :B1 )

INSERT Ernst Stavro Blofeld INSERT INTO ASSOCIATES( EMP_ID, EMP_NAME, JOB_TITLE) VALUES(  #1(1):4 #2(20):Ernst Stavro Blofeld #3(
			     :B3 , :B2 , :B1 )						 19):CRIMINAL MASTERMIND

INSERT Emilio Largo	    INSERT INTO ASSOCIATES( EMP_ID, EMP_NAME, JOB_TITLE) VALUES(  #1(1):5 #2(12):Emilio Largo #3(18):Depu
			     :B3 , :B2 , :B1 )						 ty Evil Genius

INSERT Hans		    insert into associates( emp_id, emp_name, job_title)
			    values(6, 'Hans', 'Bodyguard and Piranha keeper')

UPDATE Odd Job		    update associates
			    set job_title = 'VALET'
			    where emp_id = 1

DELETE Odd Job		    delete from associates
			    where emp_id = 1

UPDATE Jaws		    update associates
			    set job_title = 'HENCHPERSON'
			    where job_title in ('HENCHMAN', 'HENCHWOMAN')

UPDATE Mayday		    update associates
			    set job_title = 'HENCHPERSON'
			    where job_title in ('HENCHMAN', 'HENCHWOMAN')


10 rows selected.

Looks like the Piranhas will be going hungry…for now !

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s