Forensic DBA: Oracle LogMiner Helps Detect Sabotage

Some time ago, one of our customers contacted us to help them recover from a situation where one employee, departing the company, left behind quite a bit of hidden damage. (That there weren’t proper security and auditing policies in place is another story.)

What application-support discovered was that there were no problems with data deleted or changed, but rather something was changed in the Oracle schemas. After more investigation, they suspected PL/SQL procedures and packages. We had an option to restore the database to a certain point in time and try to capture previous versions. Using LogMiner was another idea and, as we later saw, a superior one.

We knew the time-frame when harmful changes could have been made, so we made sure that all archivelogs for that period were available. The next step was to start LogMiner. This was a 10g database so it was simple:

SQL> alter session set nls_date_format='yyyy-mm-dd hh24:mi:ss';

Session altered.

SQL> begin
  2  dbms_logmnr.start_logmnr(
  3  startTime => '2007-04-16 00:00:00',
  4  endTime => '2007-04-20 00:00:00',
  5  options => dbms_logmnr.DICT_FROM_ONLINE_CATALOG + dbms_logmnr.CONTINUOUS_MINE);
  6  end;
  7  /

PL/SQL procedure successfully completed.

First, we extracted all the DDLs from that time-frame using:

select timestamp, username, session_info, sql_redo, info
  from v$logmnr_contents
  where operation='DDL';

We found that several stored procedures were changed a few times right before the employee left. Okay, nothing new so far. LogMiner doesn’t generate UNDO statements for DDLs statements. However, we can extract transaction IDs for DDLs we’re interested in. The key column here is XID:

select xid, substr(sql_redo,1,100)
  from v$logmnr_contents
  where operation='DDL' and lower(sql_redo) like 'create%procedure%';

It also became apparent that some procedures were changed several times, so the database restore would be more tricky — we would need to restore several times, and each time to the previous timestamp, based on the object modification timestamp.

Knowing that the PL/SQL text is stored in SYS table SOURCE$, it was relatively easy to find out that Oracle deletes the old content and inserts the new one. So we needed only to capture the undo SQL for the SOURCE$ table for the relevant transactions (column XID):

SQL> select sql_undo from v$logmnr_contents where xid='02000B006E8B0000' and table_name='SOURCE$' and operation='DELETE';

SQL_UNDO                                                                                                                                                                                                
-------------------------------------------------------------------
insert into "SYS"."SOURCE$"("OBJ#","LINE","SOURCE") values ('94958','1','PROCEDURE super_proc_name  
');                                                                                                                                                                                                     

insert into "SYS"."SOURCE$"("OBJ#","LINE","SOURCE") values ('94958','2','(some_argument in varchar2)                                                                                                      
...

insert into "SYS"."SOURCE$"("OBJ#","LINE","SOURCE") values ('94958','265','                                                                                                                             
');                                                                                                                                                                                                     

insert into "SYS"."SOURCE$"("OBJ#","LINE","SOURCE") values ('94958','266','END;                                                                                                                         
');                                                                                                                                                                                                     

266 rows selected.

Since there were quite a few procedures to recover, it would be a bit messy to manually go through inserts. So, I could either write a small sed script or just tweak my select statement. Since this was a Windows box, and since it would be more convenient to have it done once, I created the following script:

set pagesize 1000 linesize 150 heading off feedback off verify off trimspool on trimout on
undef xid
select timestamp from v$logmnr_contents where xid='&&xid' and operation='DDL';
column txt format a150
select REGEXP_REPLACE(
       REGEXP_REPLACE(sql_undo,
          'insert into "SYS"."SOURCE\$"\("OBJ#","LINE","SOURCE"\) values \(''[0-9]+'',''[0-9]+'',''',''
       ),'''\);$',''
       ) txt
  from v$logmnr_contents where xid='&&xid' and table_name='SOURCE$' and operation='DELETE';

This produces nicely formatted the previous text of a procedure changed by the DDL with the XID extracted above. You can use it to recover from CREATE OR REPLACE PROCEDURE as well as DROP PROCEDURE (or FUNCTION or PACKAGE).

LogMiner is an extremely useful tool to investigate harm done to your databases, whether it was deliberate or not. In many cases you are able to use it for recovery too, even though it might not be directly available, as it was in this case. In this particular case, the client’s legal department is going after the saboteur, who will have to pay the consequences of leaving behind evidence of his mischief.

If you are following my blogs, you might recall that I posted how Oracle LogMiner helped to track down suspicious password change. I will be posting more about LogMiner as I get to other interesting scenarios.