db2logscan Command Line Options

-retrieve option

The -retrieve command line option allows you to specify a command to retrieve log files before running scanner. This command can be a simple script that retrieves log files from another log path. It can also include space management to remove old files from the target directory. With space management, you only need a small amount of space on the target directory.

-infoLevel option

The -infoLevel command line option allows you to generate reports on the logging rate, file, flush, page, and record verbosity.

2013-02-26 15:32:09  7.307 MB/s, 60 sec,  17.6 pg/f, 0.009435 sec/f,  15.9 pg/tr, 0.186589 sec/tr, 0.008580 sec/cmt, nOpenTrans  22.7

The -infoLevel "file" adds file metadata for each log file, including file location, Format Version, CId, Log Stream Id, Log number, Log file size in pages, number of pages, first LSO, first LFS, and LSN base.

The -infoLevel "flush" adds flush metadata for each flush, including flush size in pages, flush start and end time, flush duration

the -infoLevel "page" adds page metadata for each page, including page size in bytes, first index, page flag, and page LSO.

Record 5: pageOffset=1097 lrecsize=113 lrectype=0x4E lrecflags=0x0 
recLfs=238909237 recLsn=0x5E112E20E tid=0x50C3A270
Record 6: pageOffset=1210 lrecsize=164 lrectype=0x4E lrecflags=0x0 
recLfs=238909237 recLsn=0x5E112E20F tid=0x50C3A0A4 startOfTrans 
nOpenTrans=2
...
Record 1706: pageOffset=3848 lrecsize=128 lrectype=0x4E lrecflags=0x0 
recLfs=238909238 recLsn=0x5E112E8B3 tid=0x50C3A2A8
Record 1707: pageOffset=3976 lrecsize=48 lrectype=0x84 lrecflags=0x0 
recLfs=238909238 recLsn=0x5E112E8B4 tid=0x50C3A0A4 endOfTrans nOpenTrans=13 
vts=1361921471.1(2013-02-26 15:31:11)

-transLevel option

The -transLevel command line option controls transaction information verbosity. The -infoLevel and -transLevel options are independent, and you can use any combination of the levels.

Level "summary" (default level) shows just a summary at end of run:

transTable: nOpenTran=48 openTranSize=5910673 nBuckets=1024 nAdds=45488 nCollisions=1070 collisionRate=2%

Level "open" lists open transactions at end of run:

transTable: nOpenTran=48 openTranSize=5910673 nBuckets=1024 nAdds=45488 nCollisions=1070 collisionRate=2%
bkt:0x14 Transaction 29993: tid=0x50C61C14 startTime=2013-02-26 15:35:24 endTime=NULL size=114626 length=0sec
bkt:0x1E Transaction 34440: tid=0x50C6801E startTime=2013-02-26 15:36:23 endTime=NULL size=60855 length=0sec
...

Level "all" adds start and end of each transaction during the run:

Transaction 14 start: tid=0x50C3A296 startTime=2013-02-26 15:31:09 endTime=NULL size=375 duration=0sec nOpenTrans=13
Transaction 14 end: tid=0x50C3A296 startTime=2013-02-26 15:31:09 endTime=2013-02-26 15:31:09 size=915 duration=0sec nOpenTrans=12

Compressed Log Files

When log file compression is enabled through either the logarchcompr1 or logarchcompr2 log database configuration parameters, the archived log files are compressed.

Since the db2logscan tool cannot handle compressed files, you may temporarily disable compression to generate log files for scanner.

Logging Rate

The Db2 Log Scanner retrieves timestamps from log commit records. Time is shown in the local time zone of the scanner and the time zone information is printed at the start of the record. If the scanner machine has a default time zone that is different from the database server, you should set the time zone environment variable before running the scanner to match the time zone of the database server.

The logging rate is calculated at a regular default interval of 60 seconds. However, you can also set arbitrary intervals through using the -interval option.

If all length transactions are evenly spread over, transaction duration = commit interval * nOpenTrans. Where nOpenTrans expresses the number of transactions which overlap.

Logging Rate Explanation

The sample logging output shows that db2logscan detects that files are generated on an endian that is different from that of the scanner machine.

In this case, the scanning tool will automatically switch the scanning endian to match that of the database server.

 2013-02-08 23:56:27  0.113 MB/s, 60 sec,   4.3 pg/f, 0.150000 sec/f,   1.0 pg/tr, 0.034558 sec/tr, 0.032931 sec/cmt, nOpenTrans   0.7

The sample line above shows that at one point in time within the last 60 seconds:

• The logging rate is 0.113 MB/second.
• The average flush size is 4.3 page/flush ("pg/f" field).
• The average flush duration is 0.150000 second/flush ("sec/f" field).
• The average transaction size is 1.0 page/transaction ("pg/tr" field).
• Average transaction duration is 0.035 second/transaction ("sec/tr" field). Duration is measured from the start of a transaction (first log record for the transaction is written) to the end of the transaction (commit or rollback record).
• Average commit interval is 0.032931 second ("sec/cmt" field). This is computed from elapsed time / number of commit. As commits from all applications are counted, this is a system level metric. Average commit interval of an individual application is this value multiplied by number of applications.
• The "nOpenTrans" field reports the average number of open transactions in this period. The value on this line in the sample output is 0.7. When this value is less than 1, it means that sometimes there are no open transactions (system is idle). The number of applications connected to the database can be higher than "nOpenTrans" because not all applications submit write transactions all the time (read-only transactions are not logged and therefore invisible to the scanner).

Statistical Distribution of Logging Metrics

Each log write rate number comes from a sample interval printed in the logging rate section. The following sample distribution displays an average of 4.096 MB/s.

Distribution of log write rate (unit is in MB/s):
Total 8 numbers, Sum 32.764, Min 1.362, Max 7.306, Avg 4.096
Exactly  1.362     1 numbers 12%
Exactly  1.987     1 numbers 12%
Exactly  2.399     1 numbers 12%
Exactly  3.280     1 numbers 12%
Exactly  3.942     1 numbers 12%
Exactly  5.702     1 numbers 12%
Exactly  6.786     1 numbers 12%
Exactly  7.306     1 numbers 12%

Every flush size is represented in the distribution section. The following distribution displays an average of 7.3 pages/flush.

Distribution of flush size (unit is in pages):
Total 68369 numbers, Sum 499984, Min 1, Max 370, Avg 7.3
From 1 to 1             18615 numbers 27%
From 2 to 3             17843 numbers 26%
From 4 to 7             15782 numbers 23%
From 8 to 15            9621 numbers  14%
From 16 to 31           3847 numbers  5%
From 32 to 63           1728 numbers  2%
From 64 to 127          753 numbers   1%
From 128 to 255         166 numbers   0%
From 256 to 511         14 numbers    0%

Every flush duration is represented in the distribution section. The following example displays an average flush duration of 6 millisecond/flush. You may use the -infoLevel option to see individual flushes and study longer flushes. If long flushes occur when a system is not idle, then they are likely to be real long flushes, especially if an application is simultaneously experiencing commit delays.

Distribution of flush duration (unit is in seconds):
Total 68368 numbers, Sum 476, Min 0, Max 2, Avg 0.006962
Exactly    0         67927 numbers   99%
Exactly    1         406 numbers     0%
Exactly    2         35 numbers      0%

every record scanned is represented in this distribution section.

Distribution of record size (unit is in bytes):
Total 9077093 numbers, Sum 2037934956, Min 48, Max 32840, Avg 225
From 32 to 63        112895 numbers   1%
From 64 to 127       3360867 numbers  37%
From 128 to 255      3914015 numbers  43%
From 256 to 511      613774 numbers   6%
From 512 to 1023     1037053 numbers  11%
From 1024 to 2047    2548 numbers     0%
From 2048 to 4095    27943 numbers    0%
From 4096 to 8191    6718 numbers     0%
From 8192 to 16383   1271 numbers     0%
From 16384 to 32767  8 numbers        0%
From 32768 to 65535  1 number         0%

Every completed transaction is represented in this distribution section. Transactions which remain open at end of the scan are excluded.

Distribution of transaction size (unit is in bytes):
Total 45440 numbers, Sum 2032024283, Min 48, Max 2904178, Avg 44719
From 32 to 63            12 numbers    0%
From 128 to 255          1571 numbers  3%
From 256 to 511          11314 numbers 24%
From 512 to 1023         22664 numbers 49%
From 1024 to 2047        1803 numbers  3%
From 2048 to 4095        122 numbers   0%
From 4096 to 8191        299 numbers   0%
From 8192 to 16383       117 numbers   0%
From 16384 to 32767      268 numbers   0%
From 32768 to 65535      670 numbers   1%
From 65536 to 131071     543 numbers   1%
From 131072 to 262143    3090 numbers  6%
From 262144 to 524287    2258 numbers  4%
From 524288 to 1048575   707 numbers   1%
From 2097152 to 4194303  2 numbers     0%

Every completed transaction is represented in this distribution section. Transactions which remain open at end of the scan are excluded. Similar to flush time, the timer resolution is displayed in whole seconds. As a result, all reported transaction durations will only include whole seconds. This also means that reported duration of 0 seconds and 1 second may not be accurate. If there are a large number of transactions, the overall average remains accurate.

Distribution of transaction duration (unit is in bytes):
Total 45440 numbers, Sum 7310, Min 0, Max 58, Avg 0.160871
Zero                42588 numbers    93%
From 1 to 1         1903 numbers     4%
From 2 to 3         582 numbers      1%
From 4 to 7         140 numbers      0%
From 8 to 15        146 numbers      0%
From 16 to 31       69 numbers       0%
From 32 to 63       12 numbers       0%

Distribution of commit interval (unit is in seconds):
Total 8 numbers, Sum 0.091349, Min 0.007421, Max 0.017937, Avg 0.011419
Exactly 0.007421    1 number  12%
Exactly 0.008494    1 number  12%
Exactly 0.008580    1 number  12%
Exactly 0.009192    1 number  12%
Exactly 0.012486    1 number  12%
Exactly 0.012782    1 number  12%
Exactly 0.014457    1 number  12%
Exactly 0.017937    1 number  12%

Distribution of number of open transactions

Each time the number of open transaction changes (a transaction is starting or ending), a sample point is taken.

Distribution of number of open transactions:
Total 90928 numbers, Sum 2712630, Min 1, Max 55, Avg 29.8
From 1 to 1     1 number       0%
From 2 to 3     2 numbers      0%
From 4 to 7     4 numbers      0%
From 8 to 15    2072 numbers   2%
From 16 to 31   56303 numbers  61%
From 32 to 63   32546 numbers  35%