Dieser Monatstipp zeigt, wie mit Hilfe des Tools Logminer Archive Log Dateien analysiert werden können.
Der Fokus liegt auf den folgenden Fragestellungen:
Des Weiteren wäre es natürlich möglich den Logminer auch für eine Analyse bezüglich SQL Undo und Redo Statements zu nutzen, dies soll aber nicht Inhalt dieses Monatstipps sein.
In diesem Tipp wird davon ausgegangen, dass SUPPLEMENTAL LOGGING für die Datenbank aktiv ist. Ist dies nicht der Fall, sind aus den Archive Log Dateien keine vollständigen Informationen extrahierbar. Allgemeine Informationen zum Starten und Stoppen des Logminers finden Sie in folgendem Monatstipp.
Für die Fragestellung des aktuellen Monatstipps wurden Testszenarios aufgesetzt, um die Analysen übersichtlich zu halten und das Verhalten gut zeigen zu können. Dazu wurden drei Datenbank-Benutzer mit jeweils fünf Tabellen angelegt. In den Tests liefen Prozesse, die DML-Statements auf die Tabellen absetzten, damit wir etwas haben, was wir dann mit dem Logminer auswerten können. Die Prozesse protokollierten alle von ihnen abgesetzte Statements in eine Tabelle mit Namen REDOCOUNTABLE, so dass diese Daten mit den Erkenntnissen aus der Logminer Auswertung auf Stimmigkeit vergleichen werden können.
Hier wurde ein Prozess aufgerufen, der – unter Berücksichtigung einer maximalen Anzahl von Operations – willkürlich Insert, Update und Delete Statements auf die Testtabellen absetzt. Um in der nachfolgenden Auswertung unserer Tests einen eindeutigen Ausschlag sehen zu können, wurde der Testlauf so konfiguriert, das auf eine Tabelle eine Art von DML sehr viel häufiger stattfindet (hier die Tabelle: REDOLOAD3.REDOLOADTABLE5). Der Prozess protokollierte folgende Aktionen:
REDOLOAD1
REDOLOADTABLE1
Inserted: 45 - Updated: 120 - Deleted: 66
REDOLOADTABLE2
Inserted: 110 - Updated: 229 - Deleted: 125
REDOLOADTABLE3
Inserted: 111 - Updated: 245 - Deleted: 115
REDOLOADTABLE4
Inserted: 116 - Updated: 233 - Deleted: 127
REDOLOADTABLE5
Inserted: 65 - Updated: 115 - Deleted: 57
REDOLOAD2
REDOLOADTABLE1
Inserted: 123 - Updated: 228 - Deleted: 102
REDOLOADTABLE2
Inserted: 260 - Updated: 484 - Deleted: 224
REDOLOADTABLE3
Inserted: 204 - Updated: 464 - Deleted: 232
REDOLOADTABLE4
Inserted: 237 - Updated: 439 - Deleted: 256
REDOLOADTABLE5
Inserted: 107 - Updated: 234 - Deleted: 119
REDOLOAD3
REDOLOADTABLE1
Inserted: 76 - Updated: 117 - Deleted: 69
REDOLOADTABLE2
Inserted: 112 - Updated: 227 - Deleted: 115
REDOLOADTABLE3
Inserted: 133 - Updated: 240 - Deleted: 114
REDOLOADTABLE4
Inserted: 132 - Updated: 232 - Deleted: 113
REDOLOADTABLE5
Inserted: 51 - Updated: 2615 - Deleted: 64
Man sieht, dass die Tabelle REDOLOADTABLE5 des Benutzers REDOLOAD3 eine Lastspitze von 2615 Update Statements hat.
Damit sind die Vorbereitungen abgeschlossen, es wurde „künstlich“ DML erzeugt und die Analyse mit dem Logminer kann beginnen. Schauen wir nun also, ob sich aus den Archive Log Dateien die 2.615 Updates auf die Tabelle REDOLOAD3.REDOLOADTABLE5 herauslesen lassen. Die Analyse ab diesem Punkt würde genauso auf produktiven Datenbanken stattfinden und an ihrem Ende wäre dann auch für uns unbekannte Prozesse klar, welche Tabellen/Zeilen/Blöcke von vielen DML Statements betroffen sind.
Der Logminer ist konfiguriert und gestartet, dann kann es losgehen!
Hinzufügen der entsprechenden Archive Log Dateien zur Logminer Analyse.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6739_gj1k64fd_.arc', options => DBMS_LOGMNR.NEW);
PL/SQL procedure successfully completed.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6740_gj1k8ljs_.arc');
PL/SQL procedure successfully completed.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6741_gj1kc0nr_.arc');
PL/SQL procedure successfully completed.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6742_gj1kfcw2_.arc');
PL/SQL procedure successfully completed.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6743_gj1khwyn_.arc');
PL/SQL procedure successfully completed.
SQL> execute dbms_logmnr.add_logfile(logfilename => '/u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6744_gj1kknv1_.arc');
PL/SQL procedure successfully completed.
Danach können wir in der Tabelle v$logmnr_logs alle für den Logminer eingetragenen Archive Log Dateien sehen.
SQL> SET linesize 1000
SQL> col filename FOR a100
SQL> SELECT log_id, filename, db_name FROM V$LOGMNR_LOGS;
LOG_ID FILENAME DB_NAME
---------- ---------------------------------------------------------------------------------------------------- --------
6739 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6739_gj1k64fd_.arc ASDF
6740 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6740_gj1k8ljs_.arc ASDF
6741 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6741_gj1kc0nr_.arc ASDF
6742 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6742_gj1kfcw2_.arc ASDF
6743 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6743_gj1khwyn_.arc ASDF
6744 /u01/app/oracle/fast_recovery_area/ASDF/archivelog/2019_06_12/o1_mf_1_6744_gj1kknv1_.arc ASDF
6 rows selected.
Mit dem Kommando execute DBMS_LOGMNR.START_LOGMNR(options => DBMS_LOGMNR.DICT_FROM_ONLINE_CATALOG); wird der Logminer gestartet.
Darauffolgend kann über die Tabelle V$LOGMNR_CONTENTS die Analyse der Daten aus den Archive Log Dateien beginnen.
Die Tabelle V$LOGMNR_CONTENTS hat folgende Struktur.
SQL> desc V$LOGMNR_CONTENTS
Name Null? Type
----------------------------------------- -------- ----------------------------
SCN NUMBER
START_SCN NUMBER
COMMIT_SCN NUMBER
TIMESTAMP DATE
START_TIMESTAMP DATE
COMMIT_TIMESTAMP DATE
XIDUSN NUMBER
XIDSLT NUMBER
XIDSQN NUMBER
XID RAW(8)
PXIDUSN NUMBER
PXIDSLT NUMBER
PXIDSQN NUMBER
PXID RAW(8)
TX_NAME VARCHAR2(256)
OPERATION VARCHAR2(32)
OPERATION_CODE NUMBER
ROLLBACK NUMBER
SEG_OWNER VARCHAR2(32)
SEG_NAME VARCHAR2(256)
TABLE_NAME VARCHAR2(32)
SEG_TYPE NUMBER
SEG_TYPE_NAME VARCHAR2(32)
TABLE_SPACE VARCHAR2(32)
ROW_ID VARCHAR2(18)
USERNAME VARCHAR2(30)
OS_USERNAME VARCHAR2(4000)
MACHINE_NAME VARCHAR2(4000)
AUDIT_SESSIONID NUMBER
SESSION# NUMBER
SERIAL# NUMBER
SESSION_INFO VARCHAR2(4000)
THREAD# NUMBER
SEQUENCE# NUMBER
RBASQN NUMBER
RBABLK NUMBER
RBABYTE NUMBER
UBAFIL NUMBER
UBABLK NUMBER
UBAREC NUMBER
UBASQN NUMBER
ABS_FILE# NUMBER
REL_FILE# NUMBER
DATA_BLK# NUMBER
DATA_OBJ# NUMBER
DATA_OBJV# NUMBER
DATA_OBJD# NUMBER
SQL_REDO VARCHAR2(4000)
SQL_UNDO VARCHAR2(4000)
RS_ID VARCHAR2(32)
SSN NUMBER
CSF NUMBER
INFO VARCHAR2(64)
STATUS NUMBER
REDO_VALUE NUMBER
UNDO_VALUE NUMBER
SAFE_RESUME_SCN NUMBER
CSCN NUMBER
OBJECT_ID RAW(16)
EDITION_NAME VARCHAR2(30)
CLIENT_ID VARCHAR2(64)
SRC_CON_NAME VARCHAR2(30)
SRC_CON_ID NUMBER
SRC_CON_UID NUMBER
SRC_CON_DBID NUMBER
SRC_CON_GUID RAW(16)
CON_ID NUMBER
Als erster Analyseschritt wird ein SELECT ausgeführt, der Operationen auf die einzelnen Tabellen anhand der aus dem Logminer gewonnen Daten aufschlüsselt.
SQL> set linesize 1000
SQL> set pagesize 1000
SQL> col SEG_OWNER for a50
SQL> col SEG_NAME for a50
SQL> select SEG_OWNER, SEG_NAME, operation, count(operation) as Amount from V$LOGMNR_CONTENTS where SEG_OWNER<>'SYS' group by SEG_OWNER, SEG_NAME, operation order by 4 desc;
SEG_OWNER SEG_NAME OPERATION AMOUNT
-------------------------------------------------- -------------------------------------------------- -------------------------------- ----------
REDOLOAD3 REDOLOADTABLE5 UPDATE 2615
REDOLOAD2 REDOLOADTABLE2 UPDATE 484
REDOLOAD2 REDOLOADTABLE3 UPDATE 464
REDOLOAD2 REDOLOADTABLE4 UPDATE 439
REDOLOAD2 REDOLOADTABLE2 INSERT 260
REDOLOAD2 REDOLOADTABLE4 DELETE 256
REDOLOAD1 REDOLOADTABLE3 UPDATE 245
REDOLOAD3 REDOLOADTABLE3 UPDATE 240
REDOLOAD2 REDOLOADTABLE4 INSERT 237
REDOLOAD2 REDOLOADTABLE5 UPDATE 234
REDOLOAD1 REDOLOADTABLE4 UPDATE 233
REDOLOAD2 REDOLOADTABLE3 DELETE 232
REDOLOAD3 REDOLOADTABLE4 UPDATE 232
REDOLOAD1 REDOLOADTABLE2 UPDATE 229
REDOLOAD2 REDOLOADTABLE1 UPDATE 228
REDOLOAD3 REDOLOADTABLE2 UPDATE 227
REDOLOAD2 REDOLOADTABLE2 DELETE 224
REDOLOAD2 REDOLOADTABLE3 INSERT 204
REDOLOAD3 REDOLOADTABLE3 INSERT 133
REDOLOAD3 REDOLOADTABLE4 INSERT 132
REDOLOAD1 REDOLOADTABLE4 DELETE 127
REDOLOAD1 REDOLOADTABLE2 DELETE 125
REDOLOAD2 REDOLOADTABLE1 INSERT 123
REDOLOAD1 REDOLOADTABLE1 UPDATE 120
REDOLOAD2 REDOLOADTABLE5 DELETE 119
REDOLOAD3 REDOLOADTABLE1 UPDATE 117
REDOLOAD1 REDOLOADTABLE4 INSERT 116
REDOLOAD3 REDOLOADTABLE2 DELETE 115
REDOLOAD1 REDOLOADTABLE3 DELETE 115
REDOLOAD1 REDOLOADTABLE5 UPDATE 115
REDOLOAD3 REDOLOADTABLE3 DELETE 114
REDOLOAD3 REDOLOADTABLE4 DELETE 113
REDOLOAD3 REDOLOADTABLE2 INSERT 112
REDOLOAD1 REDOLOADTABLE3 INSERT 111
REDOLOAD1 REDOLOADTABLE2 INSERT 110
REDOLOAD2 REDOLOADTABLE5 INSERT 107
REDOLOAD2 REDOLOADTABLE1 DELETE 102
REDOLOAD3 REDOLOADTABLE1 INSERT 76
REDOLOAD3 REDOLOADTABLE1 DELETE 69
REDOLOAD1 REDOLOADTABLE1 DELETE 66
REDOLOAD1 REDOLOADTABLE5 INSERT 65
REDOLOAD3 REDOLOADTABLE5 DELETE 64
REDOLOAD1 REDOLOADTABLE5 DELETE 57
REDOLOAD3 REDOLOADTABLE5 INSERT 51
REDOLOAD1 REDOLOADTABLE1 INSERT 45
45 rows selected.
Da es sich in diesem Fall um eine Test-Datenbank handelt, gab es keine anderen Aktionen auf der Datenbank. Die internen Aktionen wurden über die WHERE Bedingung SEG_OWNER<>'SYS' ausgeschlossen. Der SELECT zeigt, dass die Tabelle REDOLOADTABLE5 vom User REDOLOAD3 mit 2615 Updates die meisten Aktionen hatte. Dies entspricht exakt dem Wert des Testszenarios.
Wir stoppen diesen Test an diesem Punkt. Würde es sich jedoch um ein reales Szenario auf einer „richtigen“ Datenbank handeln, wäre die folgende Aufgabe zu ermitteln, welcher User bzw. welches Programm dieses Statement abgesetzt hat. Dort könnten wir nun gezielt nachfragen, ob es noch weitere solcher Aktionen geben soll, so dass wir das Filesystem für Archive Log Dateien dauerhaft vergrößern müssen.
Hier analysieren wir, ob es Zeilen gibt, die besonders stark frequentiert wurden. Wir nutzen die im ersten Test erzeugte Protokoll-Tabelle REDOCOUNTABLE zur Analyse. Wie bereits zu Beginn erwähnt, protokolliert hier der Testprozess alle Aktionen. REDOCOUNTTABLE. Wir können diese Tabelle gut in unserem Analyse-Beispiel nutzen.
Im ersten Schritt selektieren wir alle ROWIDs, auf die mehr als 10 Aktionen ausgeführt wurden:
SQL> set linesize 1000
SQL> set pagesize 1000
SQL> col SEG_OWNER for a50
SQL> col SEG_NAME for a50
SQL> select SEG_OWNER, SEG_NAME, ROW_ID, operation, count(ROW_ID) as Amount from V$LOGMNR_CONTENTS where seg_owner is not null group by SEG_OWNER, SEG_NAME, ROW_ID, operation having count(ROW_ID)>10 order by 5 desc;
SEG_OWNER SEG_NAME ROW_ID OPERATION AMOUNT
-------------------------------------------------- -------------------------------------------------- ------------------ -------------------------------- ----------
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAd UPDATE 2730
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAV UPDATE 968
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAX UPDATE 932
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAW UPDATE 900
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAb UPDATE 487
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAc UPDATE 477
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAS UPDATE 476
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAR UPDATE 471
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAQ UPDATE 464
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAY UPDATE 460
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAa UPDATE 454
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAU UPDATE 453
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAZ UPDATE 262
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAT UPDATE 237
SYS REDOCOUNTTABLE AAAH/1AABAAALTpAAP UPDATE 231
15 rows selected.
Am Output erkennt man welche Tabelle und Zeile am meisten frequentiert wurde. - An erster Stelle steht die ROWID AAAH/1AABAAALTpAAd der Tabelle REDOCOUNTTABLE, sie wurde 2730-mal upgedated. Weitere ROWIDs sind zum Beispiel AAAH/1AABAAALTpAAV, AAAH/1AABAAALTpAAX und AAAH/1AABAAALTpAAW.
An Hand ihrer ROWIDs können die Zeilen selektiert werden:
SQL> select rowid, c.* from sys.REDOCOUNTTABLE c where rowid in ('AAAH/1AABAAALTpAAd', 'AAAH/1AABAAALTpAAV', 'AAAH/1AABAAALTpAAX', 'AAAH/1AABAAALTpAAW');
ROWID TABLEOWNER TABLENAME INSERTED UPDATED DELETED
------------------ --------------- -------------------- ---------- ---------- ----------
AAAH/1AABAAALTpAAV REDOLOAD2 REDOLOADTABLE2 260 484 224
AAAH/1AABAAALTpAAW REDOLOAD2 REDOLOADTABLE3 204 464 232
AAAH/1AABAAALTpAAX REDOLOAD2 REDOLOADTABLE4 237 439 256
AAAH/1AABAAALTpAAd REDOLOAD3 REDOLOADTABLE5 51 2615 64
SQL>
Wir erkennen: die 2730 Updates sind die Summe aus INSERTs, UPDATEs und DELETEs auf die Testtabellen, die vom Testprozess in der Tabelle REDOCOUNTTABLE mitprotokolliert wurden.
Der Logminer eignet sich auch, um „Hot“ Blocks zu finden. Für diesen Test wird jede der 15 Testtabellen auf einen einzigen Datensatz „eingedampft“. So erzeugen wir bei nachfolgenden Updates künstlich „Hot“ Blocks und können einen Effekt sehen.
Der Testprozess protokollierte:
REDOLOADTABLE1
Inserted: 0 - Updated: 242 - Deleted: 0
REDOLOADTABLE2
Inserted: 0 - Updated: 489 - Deleted: 0
REDOLOADTABLE3
Inserted: 0 - Updated: 3027 - Deleted: 0
REDOLOADTABLE4
Inserted: 0 - Updated: 475 - Deleted: 0
REDOLOADTABLE5
Inserted: 0 - Updated: 222 - Deleted: 0
REDOLOAD2
REDOLOADTABLE1
Inserted: 0 - Updated: 462 - Deleted: 0
REDOLOADTABLE2
Inserted: 0 - Updated: 922 - Deleted: 0
REDOLOADTABLE3
Inserted: 0 - Updated: 944 - Deleted: 0
REDOLOADTABLE4
Inserted: 0 - Updated: 894 - Deleted: 0
REDOLOADTABLE5
Inserted: 0 - Updated: 474 - Deleted: 0
REDOLOAD3
REDOLOADTABLE1
Inserted: 0 - Updated: 205 - Deleted: 0
REDOLOADTABLE2
Inserted: 0 - Updated: 455 - Deleted: 0
REDOLOADTABLE3
Inserted: 0 - Updated: 460 - Deleted: 0
REDOLOADTABLE4
Inserted: 0 - Updated: 489 - Deleted: 0
REDOLOADTABLE5
Inserted: 0 - Updated: 242 - Deleted: 0
Die Auswertung über den Logminer sieht dann wie folgt aus:
SQL> set linesize 1000
SQL> set pagesize 1000
SQL> col SEG_OWNER for a50
SQL> col SEG_NAME for a50
SQL> select SEG_OWNER, SEG_NAME, operation, count(operation) as Amount from V$LOGMNR_CONTENTS where SEG_OWNER<>'SYS' group by SEG_OWNER, SEG_NAME, operation order by 4 desc;
SEG_OWNER SEG_NAME OPERATION AMOUNT
-------------------------------------------------- -------------------------------------------------- -------------------------------- ----------
REDOLOAD1 REDOLOADTABLE3 UPDATE 3027
REDOLOAD2 REDOLOADTABLE3 UPDATE 944
REDOLOAD2 REDOLOADTABLE2 UPDATE 922
REDOLOAD2 REDOLOADTABLE4 UPDATE 894
REDOLOAD3 REDOLOADTABLE4 UPDATE 489
REDOLOAD1 REDOLOADTABLE2 UPDATE 489
REDOLOAD1 REDOLOADTABLE4 UPDATE 475
REDOLOAD2 REDOLOADTABLE5 UPDATE 474
REDOLOAD2 REDOLOADTABLE1 UPDATE 462
REDOLOAD3 REDOLOADTABLE3 UPDATE 460
REDOLOAD3 REDOLOADTABLE2 UPDATE 455
REDOLOAD3 REDOLOADTABLE5 UPDATE 242
REDOLOAD1 REDOLOADTABLE1 UPDATE 242
REDOLOAD1 REDOLOADTABLE5 UPDATE 222
REDOLOAD3 REDOLOADTABLE1 UPDATE 205
15 rows selected.
SQL>
„Hot“ Blocks lassen sich über die Block ID ermitteln:
SQL> select SEG_OWNER, SEG_NAME, DATA_BLK#, count(DATA_BLK#) from V$LOGMNR_CONTENTS where SEG_OWNER<>'SYS' and SEG_OWNER<>'PERFSTAT' group by SEG_OWNER, SEG_NAME, DATA_BLK# order by 4 desc;
SEG_OWNER SEG_NAME DATA_BLK# COUNT(DATA_BLK#)
-------------------------------------------------- -------------------------------------------------- ---------- ----------------
REDOLOAD1 REDOLOADTABLE3 212 3027
REDOLOAD2 REDOLOADTABLE3 252 944
REDOLOAD2 REDOLOADTABLE2 244 922
REDOLOAD2 REDOLOADTABLE4 260 894
REDOLOAD3 REDOLOADTABLE4 300 489
REDOLOAD1 REDOLOADTABLE2 204 489
REDOLOAD1 REDOLOADTABLE4 220 475
REDOLOAD2 REDOLOADTABLE5 268 474
REDOLOAD2 REDOLOADTABLE1 236 462
REDOLOAD3 REDOLOADTABLE3 292 460
REDOLOAD3 REDOLOADTABLE2 284 455
REDOLOAD3 REDOLOADTABLE5 308 242
REDOLOAD1 REDOLOADTABLE1 196 242
REDOLOAD1 REDOLOADTABLE5 228 222
REDOLOAD3 REDOLOADTABLE1 276 205
15 rows selected.
Der Output zeigt deutlich, dass auf Block 212 (welcher die einzige Zeile der Tabelle REDOLOADTABLE3 des Benutzers REDOLOAD1 enthält) 3027 Aktionen ausgeführt wurden. Dies entspricht exakt den Updates auf die Tabelle.
Abschließend stoppen wir den Logminer mit folgendem Befehl:
execute DBMS_LOGMNR.END_LOGMNR();
Dies sind nur einfache Beispiele. Je nach Komplexität der Applikation sind unter anderem weitere Analyse-Schritte nötig. Diese können sich für jeden einzelnen Fall unterscheiden. Gerne können wir Ihnen bei der Analyse behilflich sein.
In unserer Know-How Datenbank finden Sie mehr als 300 ausführliche Beiträge zu den
Oracle-Themen wie DBA, SQL, PL/SQL, APEX und vielem mehr.
Hier erhalten Sie Antworten auf Ihre Fragen.