Sybase - Lire les journaux transactions avec dbcc log

Logo

Introduction

Il est tout à fait possible de lire les enregistrements dans un journal de transactions pour une base de données grâce à la commande dbcc log. La commande dbcc log est non documentée mais peut éventuellement être utilisée ponctuellement dans un environnement où les journaux de transactions (syslogs) sont sauvegardés afin de déterminer par exemple si des ordres spécifiques sont passés sur un objet : ceci suppose bien entendu que l’option 'trunc log on chkpt' ne soit pas activée sur la base de données pour laquelle on désire scruter syslogs.

La commande dbcc log

Pour pouvoir utiliser la commande dbcc log, le trace flag 3604 doit être activé.

Syntaxe de la commande dbcc log

dbcc log (dbid, objid, pageno, rowno, nrecs, xact_type, printopt [0|1])

Dans cette commande dbcc log :

Paramètre Description
dbid ID de la base de données. Pour récupérer l’identifiant d’une base de données : 
select db_id('database name')
objid Peut avoir une valeur négative (< 0), égale à 0 (=0), ou supérieure à 0 (> 0). Si objid est supérieur à 0 et que pageno = 0 et rowno =0, dans ce cas tous les enregistrements dans le journal des transactions syslogs faisant référence à l’objet ayant l’identifiant objid sont affichés. Pour récupérer l’identifiant d’un objet : 
use db_name
go
select object_id('object_name')
go
pageno numéro de page dans le journal des transactions syslogs.
rowno numéro de ligne dans le journal des transactions syslogs.
nrecs nombre d’enregistrements dans le journal des transactions syslogs et la direction de scan dans syslogs.
xact_type Type d’évènement à rechercher dans le journal des transactions syslogs. -1 spécifie que l’on souhaite afficher tous les types d’enregistrement dans syslogs.
printopt 0, affiche l’entête et les données de l’enregistrement dans syslogs. 1, affiche uniquement l’entête de l’enregistrement dans syslogs

Chaque transaction dans syslogs possède un identifiant sessionid (pageno / rowno), identifiant qui indique la localisation de la transaction dans syslogs ( numéro de page / numéro de ligne).

Direction de scan dans syslogs

Dans la commande dbcc log, nrecs permet de spécifier lors la lecture du journal des transactions si l’on doit démarrer au début du journal des transactions (forward scan) ou à la fin du journal des transactions (backward scan).

Par exemple : pour visualiser les 10 premiers enregistrements dans le journal des transactions

dbcc traceon(3604)
go
dbcc log(5,0,0,0,10,-1,1)
go
LOG SCAN DEFINITION:
     Database id : 5
     Forward scan: starting at begining of log
     maximum of 10 log records.

Par exemple : pour visualiser les 10 derniers enregistrements dans le journal des transactions

dbcc traceon(3604)
go
dbcc log(5,0,0,0,-10,-1,1)
go
LOG SCAN DEFINITION:
     Database id : 5
     Backward scan: starting at end of log
     maximum of 10 log records.

Types d’évènements dans syslogs

Le paramètre type (entier allant de 0 à 82 pour Sybase ASE 12.5.2) permet de spécifier l’évènement à rechercher dans le journal des transactions syslogs :

Par exemple, pour retrouver les insertions dans les tables DOL (Data Only Locking) :

dbcc traceon(3604)
do
dbcc log(5,0,0,0,0,63,1)
go

Tous les évènements sont donnés dans le tableau qui suit :

Id / Code Opération Description
-1 ALL RECORDS 0 BEGINXACT 1 CHSYSIND 2 SWITCHTO 3 RETURN 4 INSERT 5 DELETE 6 INSIND 7 IINSERT 8 IDELETE 9 MODIFY 10 NOOP 11 INOOP 12 DNOOP 13 ALLOC 14 DBNEXTID 15 EXTENT 16 SPLIT 17 CHECKPOINT 18 SAVEXACT 19 CMD 20 SOPGDEALLOC 21 DEALLOC 22 DROPEXTS 23 AEXTENT 24 SALLOC 25 PGCHGSYSIND 26 CLR 27 SORT 28 SODEALLOC 29 ALTDB 30 ENDXACT 31 SORTTS 32 TEXTINSERT 33 INOOPTEXT 34 DNOOPTEXT 35 INSINDTEXT 36 TEXTDELETE 37 OAMALLOC 38 OAMDEALLOC 39 OAMINSERT 40 OAMDELETE 41 OAMCREATE 42 CMDNOOP 43 EXECBEGIN 44 EXECEND 45 SYNCDPDB 46 TRUNCTAB 47 SYNCLDDB 48 SYNCLDXACT 49 ROWIMAGE 50 CMDTEXT 51 OAMENTRYMOVE 52 OAMATPUT 53 DROPCOLUMN 54 LOGDEALLOC 55 CTRLPGMODIFY 56 DEFINDROW 57 DISTMAP 58 OBJINFO 59 COLINFO 60 PREPARE 61 BEGINTOPACTION 62 ENDTOPACTION 63 DOL_INSERT 64 DOL_INSIND 65 DOL_UPDATE 66 DOL_DELETE 67 DOL_GC 68 DOL_UNOOP 69 ALLOC_NOLINK 70 DOL_DNOOP 71 BT_INSERT 72 BT_DELETE 73 BT_SPLIT 74 BT_GC 75 SYSCATALOG_ROW 76 ENDSORT 77 DROPEXTSMAP 78 BT_REBLDLEAFS 79 BT_BATCHDELETE 80 BT_BATCHINSERT 81 DEALLOCM 82 PFTS Tous les enregistrements Démarrage d’une transaction xact Changement dans sysindexes SWITCHTO RETURN Insert sur une table non DOL Delete sur une table non DOL INSIND Insert sur un index Delete sur un index Update sur des tables non DOL NOOP INOOP DNOOP ALLOC DBNEXTID EXTENT SPLIT CHECKPOINT SAVEXACT CMD SOPGDEALLOC DEALLOC DROPEXTS AEXTENT SALLOC PGCHGSYSIND CLR SORT SODEALLOC ALTDB Fin d’une transaction xact SORTTS Direct text insert Deferred text insert Deferred text delete Indirect text insert Delete text OAMALLOC OAMDEALLOC OAMINSERT OAMDELETE OAMCREATE CMDNOOP EXECBEGIN EXECEND SYNCDPDB TRUNCTAB SYNCLDDB SYNCLDXACT ROWIMAGE CMDTEXT OAMENTRYMOVE OAMATPUT DROPCOLUMN LOGDEALLOC CTRLPGMODIFY DEFINDROW DISTMAP OBJINFO COLINFO PREPARE BEGINTOPACTION ENDTOPACTION Insert sur une table DOL DOL_INSIND Update sur une table DOL Delete sur une table DOL Garbage Collector sur une table DOL (reorg ?) DOL_UNOOP ALLOC_NOLINK DOL_DNOOP Insert sur un index d’une table DOL Delete sur un index d’une table DOL BT_SPLIT Garbage collector sur un index d’une table DOL (reorg?) SYSCATALOG_ROW ENDSORT DROPEXTSMAP BT_REBLDLEAFS BT_BATCHDELETE BT_BATCHINSERT DEALLOCM PFTS

Cas pratiques

Les cas pratiques vont reposer sur 4 objets dont les caractèristiques sont donnés ci-dessous :

Table Objid Schéma de verrouillage Structure Indexes
tbl_allpage_notxtcol 1536005472 AllPage id int name varchar(20) Index non clusterisé sur id
tbl_allpage_txtcol 1568005586 AllPage id int name varchar(20) description text Index non clusterisé sur id
tbl_dol_notxtcol 1600005700 Datarows (DOL) id int name varchar(20) Index non clusterisé sur id
tbl_dol_txtcol 1632005814 Datarows (DOL) id int name varchar(20) description text Index non clusterisé sur id

La base de données courante dans laquelle les transactions sont réalisées a l’identifiant 5.

Voici les transactions qui sont réalisées :

Transaction SQL
Transaction 1 
insert into tbl_allpage_notxtcol values (1,'name1')
Transaction 2 
update tbl_allpage_notxtcol set name='name11' where id=1
Transaction 3 
delete from tbl_allpage_notxtcol where id=1
Transaction 4 
insert into tbl_dol_notxtcol values (1,'name1')
Transaction 5 
update tbl_dol_notxtcol set name='name11' where id=1
Transaction 6 
delete from tbl_dol_notxtcol where id=1
Transaction 7 
insert into tbl_allpage_txtcol values (1,'name1','name1')
Transaction 8 
delete form tbl_allpage_txtcol where id=1
Transaction 9 
insert into tbl_dol_txtcol values (1,'name1','name1')
Transaction 10 
delete form tbl_dol_txtcol where id=1

Cas pratique 1 : Table en verrouillage allpage sans colonne texte

Dans le cas pratique 1 (transactions 1 à 3), des transactions sont réalisées sur la table tbl_allpage_notxtcol (objid 153605472), table qui ne comporte aucune colonne texte et dispose d’un index.

Pour retrouver tous les évènements dans syslogs en rapport avec la table tbl_allpage_notxtcol (les résultats sont abrégés)

dbcc log(5,1536005472,0,0,0,-1,1)
- - - - - - - -
LOG SCAN DEFINITION:
    Database id : 5
    Forward scan: starting at begining of log
    log records for object id 1536005472
    
LOG RECORDS:
    INSERT (25942,4) sessionid=25942,3
    ...
    objid=1536005472 pageno=1049 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0
    
    IINSERT (25942,5) sessionid=25942,3
    ...
    objid=1536005472 pageno=1057 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=2
    
    DELETE (25942,11) sessionid=25942,10
    ...
    objid=1536005472 pageno=1049 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0
    
    INSERT (25942,12) sessionid=25942,10
    ...
    objid=1536005472 pageno=1049 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0
    
    IDELETE (25942,15) sessionid=25942,14
    ...
    objid=1536005472 pageno=1057 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=2
    old ts=0x0000 0x000024ac new ts=0x0000 0x000024b3
    
    DELETE (25942,16) sessionid=25942,14
    ...
    objid=1536005472 pageno=1049 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0
    old ts=0x0000 0x000024af new ts=0x0000 0x000024b4

Le résultat de la commande dbcc log montre très clairement les trois transactions 1 à 3 car nous ne retrouvons que trois sessionid dans syslogs : 25942,3 | 25942,10 et 25942,14

Transaction Description
Transaction 1 (sessionid 25942,3) 
insert into tbl_allpage_notxtcol
values (1,'name1')
 évènement INSERT pour l’insertion dans la table (indid=0) évènement IINSERT pour l’insertion dans l’index (indid=2)
Transaction 2 (sessionid 25942,10) 
update tbl_allpage_notxtcol
set name='name11' where id=1
 évènement DELETE + INSERT pour l’update dans la table (indid=0)
Transaction 3 (sessionid 25942,14) 
delete from tbl_allpage_notxtcol
where id=1
 évènement IDELETE pour la suppression dans l’index (indid=2) évènement DELETE pour la suppression dans la table (indid=0)

Cas pratique 2 : Table en verrouillage allpage avec colonne texte

Dans le cas pratique 2 (transactions 7 à 8), des transactions sont réalisées sur la table tbl_allpage_txtcol (objid 1568005586), table qui comporte une colonne texte et dispose d’un index.

Pour retrouver tous les évènements dans syslogs en rapport avec la table tbl_allpage_txtcol (les résultats sont abrégés)

dbcc log(5,1568005586,0,0,0,-1,1)
- - - - - - - -
LOG SCAN DEFINITION:
    Database id : 5
    Forward scan: starting at begining of log
    log records for object id 1568005586
    
LOG RECORDS:
    ALLOC (25943,18) sessionid=25943,17
    ...
    pageno=1066 nextpg=0 prevpg=0 objid=1568005586 timestamp=0000 000024c8
    txtoff_high=255 txtoff_low=254 indid=255 freeoff=32 minlen=0
    
    TEXTINSERT (25943,19) sessionid=25943,17
    ...
    objid=1568005586 pageno=1066 offset=32 status=0x807
    cid=0 indid=255
    ...
    
    INSERT (25944,2) sessionid=25943,17
    ...
    objid=1568005586 pageno=1073 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0
    
    IINSERT (25944,3) sessionid=25943,17
    ...
    objid=1568005586 pageno=1081 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=2
    
    DEALLOC (25944,6) sessionid=25944,5
    ...
    pageno=1066 nextpg=0 prevpg=0 objid=1568005586 timestamp=0000 000024cd
    txtoff_high=255 txtoff_low=254 indid=255 freeoff=37 minlen=0
    
    IDELETE (25944,7) sessionid=25944,5
    ...
    objid=1568005586 pageno=1081 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=2
    
    DELETE (25944,8) sessionid=25944,5
    ...
    objid=1568005586 pageno=1073 offset=32 status=0x800 (0x0800 (XSTAT_EXPAGE))
    cid=0 indid=0

Le résultat de la commande dbcc log montre les deux transactions 7 à 8 car nous retrouvons deux sessionid dans syslogs : 25943,17 et 25944,15

Transaction SQL
Transaction 7 (sessionid 25943,17) 
insert into tbl_allpage_txtcol
values (1,'name1','name1')
 évènement ALLOC pour l’allocation d’une page pour la colonne text (indid=255). évènement TEXTINSERT pour l’insertion du champ texte (indid=255) évènement INSERT pour l’insertion dans la table (indid=0) évènement IINSERT pour l’insertion dans l’index (indid=2)
Transaction 8 (sessionid 25944,5) 
delete from tbl_allpage_txtcol where id=1
 évènement DEALLOC pour la désallocation de la page pour la colonne text (l’évènement TEXTDELETE ne se produit pas car la table va être vide à l’issue de la commande delete). évènement IDELETE pour la suppression dans l’index (indid=2) évènement DELETE pour la suppression dans la table (indid=0)

Cas pratique 3 : Table en verrouillage datarows (DOL) sans colonne texte

Dans le cas pratique 3 (transactions 4 à 6), des transactions sont réalisées sur la table tbl_dol_notxtcol (objid 1600005700), table qui ne comporte aucune colonne texte et dispose d’un index.

Pour retrouver tous les évènements dans syslogs en rapport avec la table tbl_dol_notxtcol (les résultats sont abrégés)

dbcc log(5,1600005700,0,0,0,-1,1)
- - - - - - - -
LOG SCAN DEFINITION:
    Database id : 5
    Forward scan: starting at begining of log
    log records for object id 1600005700
    
LOG RECORDS:
    DOL_INSERT (25943,1) sessionid=25943,0
    ...
    objectid=1600005700 pageno=1089 rowno=0 cid=0 erl=0
    
    BT_INSERT (25943,2) sessionid=25943,0
    ...
    objid=1600005700 indid=2 pageno=1105 level=0 root=1104 cid=0

    DOL_UPDATE (25943,5) sessionid=25943,4
    ...
    objectid=1600005700 pageno=1089 rowno=0 cid=0 erl=0
    
    BT_DELETE (25943,8) sessionid=25943,7
    ...
    objid=1600005700 indid=2 pageno=1105 level=0 root=1104 cid=0 status=0x00 (0x0000)
    
    DOL_DELETE (25943,9) sessionid=25943,7
    ...
    objectid=1600005700 pageno=1089 rowno=0 cid=0 erl=0

Le résultat de la commande dbcc log montre les trois transactions 4 à 6 car nous retrouvons trois sessionid dans syslogs : 25943,0 | 25943,4 et 25943,7

Transaction SQL
Transaction 4 (sessionid 25943,0) 
insert into tbl_dol_notxtcol values (1,'name1')
 évènement DOL_INSERT pour l’insertion dans la table évènement BT_INSERT pour l’insertion dans l’index (indid=2)
Transaction 5 (sessionid 25943,4) 
update tbl_dol_notxtcol
set name='name11' where id=1
 évènement DOL_UPDATE pour l’update dans la table
Transaction 6 (sessionid 25943,7) 
delete from tbl_dol_notxtcol where id=1
 évènement BT_DELETE pour la suppression dans l’index (indid=2) évènement DOL_DELETE pour la suppression dans la table

Cas pratique 4 : Table en verrouillage datarows (DOL) avec colonne texte

Dans le cas pratique 4 (transactions 9 à 10), des transactions sont réalisées sur la table tbl_dol_txtcol (objid 1632005814), table qui comporte une colonne texte et dispose d’un index.

Pour retrouver tous les évènements dans syslogs en rapport avec la table tbl_dol_txtcol (les résultats sont abrégés)

dbcc log(5,1632005814,0,0,0,-1,1)
- - - - - - - -
LOG SCAN DEFINITION:
    Database id : 5
    Forward scan: starting at begining of log
    log records for object id 1632005814
    
LOG RECORDS:
    ALLOC (25944,15) sessionid=25944,14
    ...
    pageno=1114 nextpg=0 prevpg=0 objid=1632005814 timestamp=0000 000024d8
    txtoff_high=255 txtoff_low=254 indid=255 freeoff=32 minlen=0
    
    TEXTINSERT (25944,16) sessionid=25944,14
    ...
    objid=1632005814 pageno=1114 offset=32
    cid=0 indid=255
    
    DOL_INSERT (25945,2) sessionid=25944,14
    ...
    objectid=1632005814 pageno=1121 rowno=0 cid=0 erl=0
    
    BT_INSERT (25945,3) sessionid=25944,14
    ...
    objid=1632005814 indid=2 pageno=1137 level=0 root=1136 cid=0
    
    DEALLOC (25945,6) sessionid=25945,5
    ...
    pageno=1114 nextpg=0 prevpg=0 objid=1632005814 timestamp=0000 000024dd
    txtoff_high=255 txtoff_low=254 indid=255 freeoff=37 minlen=0
    
    BT_DELETE (25945,7) sessionid=25945,5
    ...
    objid=1632005814 indid=2 pageno=1137 level=0 root=1136
    
    DOL_DELETE (25945,8) sessionid=25945,5
    ...
    objectid=1632005814 pageno=1121 rowno=0 cid=0 erl=0

Le résultat de la commande dbcc log montre les deux transactions 9 à 10 car nous retrouvons deux sessionid dans syslogs : 25944,14 et 25945, 5

Transaction SQL
Transaction 9 (sessionid 25944,14) 
insert into tbl_dol_txtcol values
        (1,'name1','name1')
 évènement ALLOC pour l’allocation d’une page pour la colonne text (indid=255). évènement TEXTINSERT pour l’insertion du champ texte (indid=255) évènement DOL_INSERT pour l’insertion dans la table (indid=0) évènement BT_INSERT pour l’insertion dans l’index (indid=2)
Transaction 10 (sessionid 25945, 5) 
delete from tbl_dol_txtcol where id=1
 évènement DEALLOC pour la désallocation de la page pour la colonne text (l’évènement TEXTDELETE ne se produit pas car la table va être vide à l’issue de la commande delete). évènement BT_DELETE pour la suppression dans l’index (indid=2) évènement DOL_DELETE pour la suppression dans la table (indid=0)

Cas pratique 5 : Retrouver le statut d’une action, la date et l’auteur

Dans les derniers cas pratiques, les actions unitaires sur des objets ont été passées en revue mais dans la plupart des cas, des informations plus précises sont nécessaires comme par exemple le statut de la transaction (commit ou rollback) et l’auteur de la transaction.

Si l’on reprend le cas pratique 1 pour la transaction 1, l’insertion dans la table tbl_allpage_notxtcol a pour identifiant de session 25942,3 . En précisant ces informations de session dans la commande dbcc log (les résultats sont abrégés) :

dbcc log(5,1536005472,25942,3,0,-1,1)
- - - - - -
LOG SCAN DEFINITION:
    Database id : 5
    Forward scan: starting at begining of log
    Log records for session id 25942,3
    
LOG RECORDS:
    BEGINXACT (25942,3) sessionid=25942,3
    ...
    spid=29 suid=1 uid=1 masterdbid=0 dtmcord=0
    name=$user_transaction time=Dec 3 2004 1:10:21:163PM
    
    INSERT (25942,4) sessionid=25942,3
    ...
    
     IINSERT (25942,5) sessionid=25942,3
    ...
    
    ENDXACT (25942,6) sessionid=25942,3
    ...
    endstat=COMMIT time=Dec 3 2004 1:10:24:163PM
    xstat=0x0 []

La section BEGINXACT indique la date et l’heure de démarrage de la transaction et l’auteur (spid=29, suid=1, uid=1).

La section ENDXACT indique quant à elle que la transaction a été validée (endstat = COMMIT) et la date et l’heure de fin de la transaction.