Using Log Miner (II) - Example



Example 1: Find all modifications in the last archived redo log
  • Mining and source db are the same
  • Using Online catalog as dictionary

Steps: (the various steps are part of a script file logmnr_sql.sh)
  1. Configure supplemental logs and NLS_DATE_FORMAT (optional)
  2. Get user credentials (UserA, UserB, System)
  3. UserA creates table UserA.EMP
  4. UserA updates rows on table UserA.EMP
  5. UserB updates rows on table UserA.EMP
  6. User System:
    • (a) archives current redo log;
    • (b) Add list of log files for mining;
    • (c) starts log miner;
    • (d) query log miner information; and
    • (e) Ends log miner section
(Initial configuration): Enable supplemental logging and set data format
SQL> alter database add supplemental log data;
SQL> alter session set nls_date_format = 'dd-mon-yyyy hh24:mi:ss';
(1) Get user credentials (UserA, UserB, System)
#!/bin/bash
# logmnr_sql.sh

LOGFILE=logminer.log

###############################################################
# Get users credentials
##############################################################

usersystem=system
echo "Enter password for system"
read -s passwds
usera=usera
echo "Enter password for usera"
read -s passwda
userb=userb
echo "Enter password for userb"
read -s passwdb
sid=${ORACLE_SID}
(cont..)
(2) UserA creates table UserA.EMP
(cont..)
###############################################################
# Log in as userA. Recreate EMP table
##############################################################

sqlplus -s /nolog << EndOfSQL >> ${LOGFILE}
connect ${usera}/${passwda} 
whenever sqlerror exit sql.sqlcode;

prompt "Connected: UserA - recreating EMP.."

drop table emp;
create table emp as
  select employee_id as empno,
         first_name || ' ' || last_name as ename,
         department_id as deptno,
         salary as salary
  from hr.employees;
grant select, update on emp to userb;

exit;
EndOfSQL

ERRORCODE=$?

#check the return code from SQL Plus
if [ $ERRORCODE != 0 ]
then
 echo ********************************
 echo "ERROR: SQL*Plus failed with error code: $ERRORCODE"
else
 echo ********************************
 echo "SQL*Plus completed successfully. Error code: $ERRORCODE"
fi
(cont..)
(3) UserA updates some rows on table UserA.EMP
(cont..)
###############################################################
# Log in as usera. update data on table EMP
##############################################################

sqlplus -s /nolog << EndOfSQL >> ${LOGFILE}
connect ${usera}/${passwda} 
whenever sqlerror exit sql.sqlcode;

prompt "Connected: UserA - Updating rows..."

set serveroutput on  
begin
  update emp set salary = salary*1.05 where deptno = 50;
  commit;
  dbms_output.put_line('salaries on dept 50 updated..');  
  declare
   cursor c_emp is
     select empno, ename, deptno, salary from emp
     where deptno = 30
     for update;
  begin
   for c_reg in c_emp loop
     update emp
      set ename = initcap(c_reg.ename)
      where current of c_emp;
     update emp
      set salary = c_reg.salary *1.10
      where current of c_emp;
   end loop;
   commit;
   dbms_output.put_line('names and salaries on dept 30 updated..');  
  end;
end;
/

exit;
EndOfSQL

ERRORCODE=$?

# Check the return code from SQL Plus
if [ $ERRORCODE != 0 ]
then
 echo ********************************
 echo "ERROR: SQL*Plus failed with error code: $ERRORCODE"
else
 echo ********************************
 echo "SQL*Plus completed successfully. Error code: $ERRORCODE"
fi
(cont..)
(4) UserB updates rows on table UserA.EMP
###############################################################
# Log in as userB. update data on table EMP
##############################################################

sqlplus -s /nolog << EndOfSQL >> ${LOGFILE}
connect ${userb}/${passwdb} 
whenever sqlerror exit sql.sqlcode;

prompt "Connected: USERB"

set serveroutput on  
begin
  update usera.emp set salary = salary*1.05 where deptno = 60;
  dbms_output.put_line('SQL%ROWCOUNT: ['|| SQL%ROWCOUNT || '] rows returned');
  commit;
  dbms_output.put_line('salaries on dept 60 updated..');  
  declare
   cursor c_emp2 is
     select empno, ename, deptno, salary from usera.emp
     where deptno = 90
     for update;
  begin
   for c_reg in c_emp2 loop
     update usera.emp
      set ename = initcap(c_reg.ename)
      where current of c_emp2;
     update usera.emp
      set salary = c_reg.salary *1.10
      where current of c_emp2;
   end loop;
   commit;
   dbms_output.put_line('names and salaries on dept 30 updated..');  
  end;
end;
/
exit;
EndOfSQL

ERRORCODE=$?

# Check the return code from SQL Plus
if [ $ERRORCODE != 0 ]
then
 echo ********************************
 echo "ERROR: SQL*Plus failed with error code: $ERRORCODE"
else
 echo ********************************
 echo "SQL*Plus completed successfully. Error code: $ERRORCODE"
fi
(cont..)
(5) Log in as SYSTEM: (a) archives current redo log; (b) Add list of log files for mining; (c) starts log miner; (d) query log miner information; and (e) Ends log miner section
###############################################################
# Log in as SYSTEM. Run Log Miner 
##############################################################
echo "Configuring Log Miner section..."

sqlplus -s /nolog << EndOfSQL >> ${LOGFILE}
connect ${usersystem}/${passwds} 
whenever sqlerror exit sql.sqlcode;

prompt "Connected: SYSTEM"


prompt " (a) Switching current log file.."
alter system archive log current;

prompt "Most recently archived log file is"
set linesize 150
select name, first_change# from v\$archived_log
 where first_time = (select max(first_time) 
                       from v\$archived_log);

prompt "(b) Configuring the list of redo log files to be mined.."

declare
  v_logname varchar2(200);
begin
  select name into v_logname
   from v\$archived_log
   where first_time = (select max(first_time) 
                         from v\$archived_log);
 dbms_logmnr.add_logfile(LOGFILENAME => v_logname, OPTIONS => dbms_logmnr.new);
end;
/

prompt "List of log files added to log miner: "
select   to_char(low_time, 'dd-mon-yy hh24:mi:ss') lowtime,
         to_char(high_time, 'dd-mon-yy hh24:mi:ss') hightime,
         type, filesize/1024/1024 Mb, filename 
from v\$logmnr_logs;

prompt "(c) Starting log miner using online catalog.."
execute dbms_logmnr.start_logmnr(options => dbms_logmnr.dict_from_online_catalog);
prompt "(d) Querying log miner results"

set linesize 150
set pagesize 80
column usr format a10
column osusr format a10
column machine_name format a10
column xid format a12
col operation format a15
col table_name format a10
col sql_redo format a30
col sql_undo format a30

select username as usr,
       os_username as osusr,
       (xidusn ||'.'|| xidslt ||'.'||xidsqn) as xid,
       operation, 
       table_name,
       sql_redo, 
       sql_undo
  from v\$logmnr_contents
  where username in ('USERA', 'USERB');

USR     OSUSR    XID        OPERATION       TABLE_NAME  SQL_REDO                       SQL_UNDO
------  -------- ---------- --------------- ----------  ------------------------------ ------------------------------
USERA   jdoe     10.12.988  START                       set transaction read write;
USERA   jdoe     1.7.928    DDL              EMP        ALTER TABLE "USERA"."EMP" RENA
                                                        ME TO "BIN$sKOUXNE/r7TgQAB/AQE
                                                        yrA==$0" ;
...
USERA   jdoe     1.7.928    DDL              EMP        drop table emp AS "BIN$sKOUXNE
                                                        /r7TgQAB/AQEyrA==$0" ;
...
USERA   jdoe     4.32.983   DDL              EMP       create table emp as
                                                        select employee_id as empno,
                                                        first_name || ' ' ||
                                                        last_name as ename,
                                                        department_id as deptno,
                                                        salary as salary
                                                        from hr.employees;
..
USERA   jdoe     4.23.984   START                       set transaction read write;
USERA   jdoe     4.32.983   DIRECT INSERT    EMP        insert into "USERA"."EMP"("EMP delete from "USERA"."EMP" wher
                                                        NO","ENAME","DEPTNO","SALARY") e "EMPNO" = '198' and "ENAME"
                                                        values ('198','Donald OConnel  = 'Donald OConnell' and "DEPTN
                                                        l','50','2600');               O" = '50' and "SALARY" = '2600
                                                                                       ' and ROWID = 'AAASdlAAEAAAAMb
                                                                                       AAA';

...
USERA   jdoe     4.32.983   DIRECT INSERT   EMP         insert into "USERA"."EMP"("EMP delete from "USERA"."EMP" wher
                                                        NO","ENAME","DEPTNO","SALARY") e "EMPNO" = '197' and "ENAME"
                                                        values ('197','Kevin Feeney',  = 'Kevin Feeney' and "DEPTNO"
                                                        '50','3000');                  = '50' and "SALARY" = '3000' a
                                                                                       nd ROWID = 'AAASdlAAEAAAAMbABq
                                                                                       ';
...
USERA   jdoe     10.31.988  DDL             EMP         grant select, update on emp to
                                                        userb;
...
USERA   jdoe     10.31.988  UPDATE          OBJ$        update "SYS"."OBJ$" set "OBJ#" update "SYS"."OBJ$" set "OBJ#"
                                                        = '75621', "DATAOBJ#" = '7562  = '75621', "DATAOBJ#" = '7562
                                                        1', "TYPE#" = '2', "CTIME" = T 1', "TYPE#" = '2', "CTIME" = T
                                                        O_DATE('22-NOV-10', 'DD-MON-RR O_DATE('22-NOV-10', 'DD-MON-RR
                                                        '), "MTIME" = TO_DATE('22-NOV- '), "MTIME" = TO_DATE('22-NOV-
                                                        10', 'DD-MON-RR'), "STIME" = T 10', 'DD-MON-RR'), "STIME" = T
                                                        O_DATE('22-NOV-10', 'DD-MON-RR O_DATE('22-NOV-10', 'DD-MON-RR
                                                        '), "STATUS" = '1', "FLAGS" =  '), "STATUS" = '1', "FLAGS" =
                                                        '0', "OID$" = NULL, "SPARE1" = '0', "OID$" = NULL, "SPARE1" =
                                                        '6', "SPARE2" = '1' where "OB  '6', "SPARE2" = '1' where "OB
                                                        J#" = '75621' and "DATAOBJ#" = J#" = '75621' and "DATAOBJ#" =
                                                        '75621' and "OWNER#" = '92' a  '75621' and "OWNER#" = '92' a
                                                        nd "TYPE#" = '2' and "CTIME" = nd "TYPE#" = '2' and "CTIME" =
                                                        TO_DATE('22-NOV-10', 'DD-MON-  TO_DATE('22-NOV-10', 'DD-MON-
                                                        RR') and "MTIME" = TO_DATE('22 RR') and "MTIME" = TO_DATE('22
                                                        -NOV-10', 'DD-MON-RR') and "ST -NOV-10', 'DD-MON-RR') and "ST
                                                        IME" = TO_DATE('22-NOV-10', 'D IME" = TO_DATE('22-NOV-10', 'D
                                                        D-MON-RR') and "STATUS" = '1'  D-MON-RR') and "STATUS" = '1'
                                                        and "FLAGS" = '0' and "OID$" I and "FLAGS" = '0' and "OID$" I
                                                        S NULL and "SPARE1" = '6' and  S NULL and "SPARE1" = '6' and
                                                        "SPARE2" = '1' and ROWID = 'AA "SPARE2" = '1' and ROWID = 'AA
                                                        AAASAABAAAU6JAAi';             AAASAABAAAU6JAAi';
..
USERA   jdoe     10.31.988    COMMIT                    commit;
USERA   jdoe     7.26.985     START                     set transaction read write;
...
USERA   jdoe     3.23.1299    START                     set transaction read write;
USERA   jdoe     3.23.1299    UPDATE    EMP          update "USERA"."EMP" set "SALA update "USERA"."EMP" set "SALA
                                                        RY" = '2730' where "EMPNO" = ' RY" = '2600' where "EMPNO" = '
                                                        198' and "ENAME" = 'Donald OCo 198' and "ENAME" = 'Donald OCo
                                                        nnell' and "DEPTNO" = '50' and nnell' and "DEPTNO" = '50' and
                                                        "SALARY" = '2600' and ROWID =  "SALARY" = '2730' and ROWID =
                                                        'AAASdlAAEAAAAMbAAA';          'AAASdlAAEAAAAMbAAA';
...
USERA   jdoe     3.23.1299    UPDATE    EMP          update "USERA"."EMP" set "SALA update "USERA"."EMP" set "SALA
                                                        RY" = '2250' where "EMPNO" = ' RY" = '3000' where "EMPNO" = '
                                                        197' and "ENAME" = 'Kevin Feen 197' and "ENAME" = 'Kevin Feen
                                                        ey' and "DEPTNO" = '50' and "S ey' and "DEPTNO" = '50' and "S
                                                        ALARY" = '3000' and ROWID = 'A ALARY" = '2250' and ROWID = 'A
                                                        AASdlAAEAAAAMbABq';            AASdlAAEAAAAMbABq';

USERA   jdoe     3.23.1299   COMMIT                     commit;
USERA   jdoe     1.12.927    START                      set transaction read write;
USERA   jdoe     1.12.92     SELECT_FOR_UPDATE EMP      select * from "USERA"."EMP" wh
                                                     ere ROWID = 'AAASdlAAEAAAAMbAA
                                                        X' for update;
...
USERA   jdoe     1.12.927    UPDATE       EMP           update "USERA"."EMP" set "ENAM update "USERA"."EMP" set "ENAM
                                                        E" = 'Den Raphaely' where "EMP E" = 'Den Raphaely' where "EMP
                                                        NO" = '114' and "ENAME" = 'Den NO" = '114' and "ENAME" = 'Den
                                                        Raphaely' and "DEPTNO" = '30'  Raphaely' and "DEPTNO" = '30'
                                                        and "SALARY" = '11000' and RO  and "SALARY" = '11000' and RO
                                                        WID = 'AAASdlAAEAAAAMbAAX';    WID = 'AAASdlAAEAAAAMbAAX';
...
USERA   jdoe     1.12.927    UPDATE       EMP           update "USERA"."EMP" set "SALA update "USERA"."EMP" set "SALA
                                                        RY" = '2750' where "EMPNO" = ' RY" = '2500' where "EMPNO" = '
                                                        119' and "ENAME" = 'Karen Colm 119' and "ENAME" = 'Karen Colm
                                                        enares' and "DEPTNO" = '30' an enares' and "DEPTNO" = '30' an
                                                        d "SALARY" = '2500' and ROWID  d "SALARY" = '2750' and ROWID
                                                        = 'AAASdlAAEAAAAMbAAc';        = 'AAASdlAAEAAAAMbAAc';

USERB   jdoe     1.12.927    COMMIT                     commit;
...
USERB   jdoe     8.21.1521   START                      set transaction read write;
USERB   jdoe     6.16.1306   UPDATE       EMP           update "USERA"."EMP" set "SALA update "USERA"."EMP" set "SALA
                                                        RY" = '9450' where "EMPNO" = ' RY" = '9000' where "EMPNO" = '
                                                        103' and "ENAME" = 'Alexander  103' and "ENAME" = 'Alexander
                                                        Hunold' and "DEPTNO" = '60' an Hunold' and "DEPTNO" = '60' an
                                                        d "SALARY" = '9000' and ROWID  d "SALARY" = '9450' and ROWID
                                                        = 'AAASdlAAEAAAAMbAAM';        = 'AAASdlAAEAAAAMbAAM';
...
USERB   jdoe     6.16.1306    COMMIT                    commit;
USERB   jdoe     4.5.983      START                     set transaction read write;
USERB   jdoe     4.5.983      SELECT_FOR_UPDA EMP       select * from "USERA"."EMP" wh
                                           TE           ere ROWID = 'AAASdlAAEAAAAMbAA
...
USERB   jdoe     4.5.983      UPDATE     EMP         update "USERA"."EMP" set "ENAM update "USERA"."EMP" set "ENAM
                                                        E" = 'Steven King' where "EMPN E" = 'Steven King' where "EMPN
                                                        O" = '100' and "ENAME" = 'Stev O" = '100' and "ENAME" = 'Stev
                                                        en King' and "DEPTNO" = '90' a en King' and "DEPTNO" = '90' a
                                                        nd "SALARY" = '24000' and ROWI nd "SALARY" = '24000' and ROWI
                                                        D = 'AAASdlAAEAAAAMbAAJ';      D = 'AAASdlAAEAAAAMbAAJ';
...
USERB   jdoe     4.5.983      COMMIT                    commit;
...
188 rows selected.

(e) End the Log Miner Section
prompt "(e) Ending log miner section.."
execute dbms_logmnr.end_logmnr();
exit;
EndOfSQL


ERRORCODE=$?

# Check the return code from SQL Plus
if [ $ERRORCODE != 0 ]
then
 echo ********************************
 echo "ERROR: SQL*Plus failed with error code: $ERRORCODE"
else
 echo ********************************
 echo "SQL*Plus completed successfully. Error code: $ERRORCODE"
fi

Using the Log Miner (I)



Using the LogMiner
  • First appeared in Oracle 8i
  • Log Miner allows for analysis of online and archived redo log files.
  • LogMiner provides a well-defined, easy-to-use, and comprehensive relational interface to redo log files

Enhancements in Oracle 11g
  • LogMiner was integrated with OEM
  • Also integrated with the new flashback transaction feature
  • Can be used from command line or through OEM

Possible uses:
  • Find out when a logical error happened and who did it.
  • This information in turn can be used to determine when to initiate time-based or change-based recovery (V$LOGMNR_CONTENTS)
  • Determine what actions are needed to perform fine-grained recovery at the transaction level (flashback transaction)
  • Support for trend analysis (find out which databases get most DMLs)
  • Support on post-facto auditing.
  • Useful to find out who has updated a given table (or set of tables).
  • Explore what happens when a DML/DDL is issued against the database

Configuring the Log Miner
Four objects are used in a LogMiner configuration:
  1. The Source database
  2. The Mining database
  3. The LogMiner dictionary - used to translate internal object identifiers to object names and external data formats.
  4. Redo log files that will be analyzed

Managing LogMiner operation:
  • Use SYS.DBMS_LOGMNR and SYS.DBMS_LOGMNR_D packages to (a) select redo log files for analysis, (b) begin and (c) end log miner section.
  • Use V$LOGMNR_CONTENTS view to query the contents of redo logs.
  • You must be connected as SYS or have EXECUTE_CATALOG_ROLE role

DBMS_LOGMNR package subprograms:
SQL> dbms_logmnr.add_logfile(LOGFILENAME => logname, OPTIONS => dbms_logmnr.new);
-- Add redo log file to a list of redo logs for LogMiner to process.
    OPTIONS:
    • new -- implicit call to dbms_logmnr.end_logmnr and start a new log miner session. Creates a new list and add the redo log.
    • addfile -- Adds the redo log to the existing list
SQL> dbms_logmnr.remove_logfile(LOGFILENAME => logname);
-- Remove redo from list
SQL>  dbms_logmnr.start_logmnr(OPTIONS => dbms_logmnr.dict_from_online_catalog);
-- Initialized the LogMiner
    OPTIONS:
    • committed_data_only
      • Return committed statements only. (none rolled back or in progress)
      • Group statements of a committed transaction.
      • Transactions returned in order.
    • skip_corruption
      • skips corruptions in the redo log (redo log block corruption)
    • ddl_dict_tracking
      • Used when dictionary is in a flat file. Updates dict references as DDL are processed
    • dict_from_online_catalog
      • directs log miner to use the online dictionary of the database when translating object names
    • dict_from_redo_logs
    • no_sql_delimiter
      • Useful if you want to use the reconstructed statements directly in a open cursor
    • no_rowid_in_stmt
    • print_pretty_sql
    • continuous_mine
      • Instructs log miner to add redo log files, as needed, until find the data on the specified SCN or timestamp
    • string_literals_in_stmt
SQL> dbms_logmnr.end_logmnr();
-- Finishes a LogMiner session
Requirements to use LogMiner
  1. Source and Mining databases
    • Both must run on the same platform
    • mining db can be the same or separate from source db
    • mining db must be same or later release of the source db
    • mining db must use same characterset (or superset) of source db
  2. LogMiner dictionary
    • Must be produced from the source db
    • Used to translate redo log information into a meaningful format
    • Used to display table and column names instead of their internal IDs.
    • Without a dictionary, LogMiner also display all values in hexadecimal format.
  3. Redo Logs
    • must be produced by the same source db
    • associated with the same database RESETLOGS SCN
    • Must be from oracle 8.0 or later (mostly 9i or later)
  4. Supplemental Logging
    • must be enabled before redo logs are generated
    • Enable with: ALTER DATABASE ADD SUPPLEMENTAL LOG DATA;
    • Logs the extra information necessary to reconstruct the SQL statement as well
      as one to revert the original action.
    • Without supplemental logging instance and media recovery is possible, but log mining,
      or reconstruction of the original SQL statement, is not possible.
SQL> select supplemental_log_data_min,supplemental_log_data_pk, 
     supplemental_log_data_fk, supplemental_log_data_all
     from v$database;

SUPPLEMENTAL_LOG_DATA_MIN SUPPLEMENTAL_LOG_DATA_PK SUPPLEMENTAL_LOG_DATA_FK SUPPLEMENTAL_LOG_DATA_ALL 
------------------------- ------------------------ ------------------------ ------------------------- 
YES                       YES                      YES                      NO                       
About the LogMiner dictionary
Used to translate the information in the redo log files into object names and display the data in alpha numeric, instead of hexadecimal format.
(a) You can use the online catalog of the source database
  • For this, the source database must be online and available
  • To use the online catalog: SQL> execute dbms_logmnr.start_logmnr( options => dbms_logmnr.dict_from_online_catalog);
(b) Can be extracted from source database into the redo log files
  • Used when the source database is not available
  • In order to extract dictionary information, the source database must be (1) open, (2) in archivelog mode, (3) with enabled archiving.
  • To extract dictionary: SQL> execute dbms_logmnr_d.build( options => dbms_logmnr_d.store_in_redo_logs);
  • The dictionary information is stored in the archived redo logs. To find out which:
    • SQL> select name from v$archived_log where dictionary_begin = 'YES';
    • SQL> select name from v$archived_log where dictionary_end = 'YES';
(c) Can be extracted from source db to flat file
  • Available for backward compatibility only. no trasactional consistency.



Example 1: Find all modifications in the last archived redo log
  • Mining and source db are the same
  • Using Online catalog as dictionary