common/log

   1 ##/bin/bash
   2 # SPDX-License-Identifier: GPL-2.0
   3 # Copyright (c) 2000-2002 Silicon Graphics, Inc.  All Rights Reserved.
   4 #
   5 # common routines for log testing
   6
   7 fulldir=$seqres.fulldir
   8 rm -rf $fulldir
   9
  10 _cleanup_logfiles()
  11 {
  12     if [ $status -eq 0 ]; then
  13         # don't keep these files around unless something went wrong
  14         rm -rf $fulldir
  15     fi
  16 }
  17
  18 _full()
  19 {
  20     echo ""            >>$seqres.full
  21     echo "*** $* ***"  >>$seqres.full
  22     echo ""            >>$seqres.full
  23 }
  24
  25 _echofull()
  26 {
  27     echo ""            | tee -a $seqres.full
  28     echo "*** $* ***"  | tee -a $seqres.full
  29     echo ""            | tee -a $seqres.full
  30 }
  31
  32 # Handle the operations which get split over Log Record
  33 # boundaries.
  34 # Oper (379)..... flags: CONTINUE
  35 # ...
  36 # Oper (0)....... flags: WAS_CONT END
  37 #
  38 # or
  39 #
  40 # Oper (379)..... flags: none
  41 # ...
  42 # Oper (0)....... flags: none
  43 #
  44 _filter_opnum()
  45 {
  46     $AWK_PROG '
  47 BEGIN {
  48         debug = 0
  49         }
  50 /^Oper/ && debug {
  51             printf "line = %s\n", $0
  52         }
  53 /^Oper/ {
  54             was_cont = 0
  55         }
  56 /^Oper/ && /flags: CONTINUE/ {
  57             # this will be the first op of split region
  58             $9 = "none" # overwrite CONTINUE flags
  59             print
  60             print "Not printing rest"
  61             was_cont = 1
  62             next
  63         }
  64 /^Oper/ && /flags: WAS_CONT END/ {
  65             # this will be the last op of split region
  66             # skip over was-continued op
  67             # we assume there can be only 1
  68             was_cont = 1
  69             next
  70         }
  71 (was_cont == 1) {
  72             # skip over any continued op stuff
  73             next
  74         }
  75         {print}
  76     '
  77 }
  78
  79 #
  80 # Filter out things that can change
  81 # We have complexities which change when log is sync'ed at different
  82 # times.
  83 # Example1: DATA FORK EXTENTS
  84 # These will not show up if inode is sync'ed sooner
  85 #       /DATA FORK EXTENTS/d;
  86 #       /INODE:/s/flags:0x5/flags:0x1/g;
  87 # define XFS_ILOG_CORE   0x001   /* log standard inode fields */
  88 # define XFS_ILOG_DEXT   0x004   /* log i_df.if_extents */
  89 #
  90 #
  91
  92 _filter_logprint()
  93 {
  94     sed '
  95         s/ver:[0-9]/ver:<VERS>/;
  96         s/version [0-9] format [0-9]/version <VERS> format <FORMAT>/;
  97         s/data device: 0x[0-9a-f][0-9a-f]*/data device: <DEVICE>/;
  98         s/log device: 0x[0-9a-f][0-9a-f]*/log device: <DEVICE>/;
  99         s/log file: \".*\"/log device: <DEVICE>/;
 100         s/daddr: [0-9][0-9]*/daddr: <DADDR>/;
 101         s/length: [0-9][0-9]*/length: <LENGTH>/;
 102         s/length: [0-9][0-9]*/length: <LENGTH>/;
 103         s/^cycle num overwrites: .*$/cycle num overwrites: <TIDS>/;
 104         s/tid: [0-9a-f][0-9a-f]*/tid: <TID>/;
 105         s/tid:0x[0-9a-f][0-9a-f]*/tid:<TID>/;
 106         s/q:0x[0-9a-f][0-9a-f]*/q:<Q>/;
 107         s/a:0x[0-9a-f][0-9a-f]*/a:<A>/g;
 108         s/blkno:0x[0-9a-f][0-9a-f]*/blkno:<BLKNO>/g;
 109         s/blkno: *[0-9][0-9]* (0x[0-9a-f]*)/blkno: <BLKNO> (<BLKNO>)/g;
 110         s/blkno: *[0-9][0-9]*/blkno: <BLKNO>/g;
 111         s/boff: [0-9][0-9]*/boff: <BOFF>/g;
 112         s/len: *[0-9][0-9]*/len:<LEN>/g;
 113         /BUF:/s/[       ]*flags:.*$//;
 114         /zeroed blocks/s/[0-9][0-9]*/<COUNT>/g;
 115         /cleared blocks/d;
 116         /log tail/s/[0-9][0-9]*/<COUNT>/g;
 117         s/atime:[0-9a-fx]*  *mtime:[0-9a-fx]*  *ctime:[0-9a-fx]*/atime:<TIME>  mtime:<TIME>  ctime:<TIME>/;
 118         s/atime 0x[0-9a-f]* mtime 0x[0-9a-f]* ctime 0x[0-9a-f]*/atime <TIME>  mtime <TIME>  ctime <TIME>/;
 119         s/block [0-9][0-9]*/block <BLOCK>/;
 120         s/icount: *[0-9][0-9]*  *ifree: *[0-9][0-9]*  *fdblks: *[0-9][0-9]*  *frext: *[0-9][0-9]*/icount:<COUNT> ifree:<FREE> fdblks:<BLOCKS> frext:<COUNT>/;
 121         s/sunit: *[0-9][0-9]*  *swidth: *[0-9][0-9]*/sunit:<SUNIT> swidth:<SWIDTH>/;
 122         s/1st: *[0-9][0-9]*  *last: *[0-9][0-9]*  *cnt: *[0-9][0-9]*  *freeblks: *[0-9][0-9]*  *longest: *[0-9][0-9]*/1st:<NUM> last:<NUM> cnt:<COUNT> freeblks:<COUNT> longest:<NUM>/;
 123         s/^uuid: *[0-9a-f-][0-9a-f-]* *format: *.*$/uuid: <UUID> format: <FORMAT>/;
 124         /flushiter:/d;
 125         /version:/,/h_size:/d;
 126         /override tail/s/[0-9][0-9]*/<TAIL_BLK>/;
 127         /^---*/d;
 128         /^===*/d;
 129         /^~~~*/d;
 130         /extended-header/d;
 131         /LOG REC AT LSN/d;
 132         /DATA FORK EXTENTS/d;
 133         s/BUF: cnt:[1-9][0-9]* total:[1-9][0-9]*.*/BUF: cnt:C total:T/;
 134         s/INO: cnt:[1-9][0-9]* total:[1-9][0-9]*.*/INO: cnt:C total:T/;
 135         s/#regs: *[1-9][0-9]*/#regs:R/;
 136         /INODE:/s/flags:0x5/flags:0x1/g;
 137         s/Oper ([0-9][0-9]*)/Oper (OPNUM)/;
 138         /^[     ]*$/d;
 139         s/  */ /g;
 140         s/ $//;
 141         s/newino: 0x[0-9a-f]*$/newino: <INO>/g
 142         s/newino:0x[0-9a-f]*$/newino:<INO>/g
 143         s/ino: 0x[0-9a-f]* flags:/ino: <INO> flags:/g
 144         s/ino:0x[0-9a-f]* flags:/ino:<INO> flags:/g
 145         s/onlink:[0-9][0-9]*/onlink:<ONLINK>/;
 146         s/gen:-*[0-9][0-9]*/gen:<GEN>/;
 147         s/gen 0x[0-9a-f][0-9a-f]*/gen <GEN>/;
 148     '|\
 149     awk '
 150         # collapse BUF DATA group into 1 line
 151         # for Oper data this can be over separate operations...ughh
 152         /BUF DATA/ {
 153                 if (!buf_data) { # 1st one
 154                     if (oper) {
 155                         print oper
 156                         oper = 0
 157                     }
 158                     print
 159                 }
 160                 buf_data = 1
 161                 oper = 0 # wont need it now
 162                 next
 163         }
 164         /^Oper/ {
 165                 # store it as we dont know if 2nd BUF DATA is to follow
 166                 if (oper) {
 167                     print oper
 168                 }
 169                 oper = $0
 170                 next
 171         }
 172         /^TRANS/ && dummy_rec == 1 {
 173                 # start printing again - dummy transaction over
 174                 dummy_rec = 0
 175         }
 176         /DUMMY1/ {
 177                 # filter out dummy transactions
 178                 dummy_rec = 1
 179                 next
 180         }
 181         {
 182                 if (dummy_rec) {
 183                     next
 184                 }
 185                 buf_data = 0
 186                 if (oper) { # now we can print out oper
 187                     print oper
 188                     oper = 0
 189                 }
 190                 print
 191         }
 192     '
 193 }
 194
 195 _check_log()
 196 {
 197     _full "clean_log : xfs_logprint"
 198     _scratch_xfs_logprint -t | tee -a $seqres.full \
 199         | head | grep -q "<CLEAN>" || _fail "DIRTY LOG"
 200 }
 201
 202 _scratch_xfs_logstate()
 203 {
 204     _scratch_xfs_logprint -t | tee -a $seqres.full | grep -q "<CLEAN>"
 205     echo $?
 206 }
 207
 208 _scratch_f2fs_logstate()
 209 {
 210     $DUMP_F2FS_PROG $SCRATCH_DEV | tee -a $seqres.full | grep -q "unmount"
 211     echo $?
 212 }
 213
 214 _scratch_ext4_logstate()
 215 {
 216     $DUMPE2FS_PROG -h $SCRATCH_DEV 2> /dev/null | tee -a $seqres.full | \
 217         grep "^Filesystem features" | grep -q needs_recovery
 218     test $? -ne 0
 219     echo $?
 220 }
 221
 222 _scratch_dump_log()
 223 {
 224         case "$FSTYP" in
 225         xfs)
 226                 _scratch_xfs_logprint
 227                 ;;
 228         f2fs)
 229                 $DUMP_F2FS_PROG $SCRATCH_DEV
 230                 ;;
 231         ext4)
 232                 $DUMPE2FS_PROG -h $SCRATCH_DEV
 233                 ;;
 234         *)
 235                 ;;
 236         esac
 237 }
 238
 239 _test_dump_log()
 240 {
 241         case "$FSTYP" in
 242         xfs)
 243                 _test_xfs_logprint
 244                 ;;
 245         f2fs)
 246                 $DUMP_F2FS_PROG $TEST_DEV
 247                 ;;
 248         ext4)
 249                 $DUMPE2FS_PROG -h $TEST_DEV
 250                 ;;
 251         *)
 252                 ;;
 253         esac
 254 }
 255
 256 _print_logstate()
 257 {
 258     case "$FSTYP" in
 259     xfs)
 260         dirty=$(_scratch_xfs_logstate)
 261         ;;
 262     f2fs)
 263         dirty=$(_scratch_f2fs_logstate)
 264         ;;
 265     ext4)
 266         dirty=$(_scratch_ext4_logstate)
 267         ;;
 268     *)
 269         ;;
 270     esac
 271
 272     if [ $dirty -ne 0 ]; then
 273         echo "dirty log"
 274     else
 275         echo "clean log"
 276     fi
 277 }
 278
 279 _print_operation()
 280 {
 281     mkdir $fulldir >/dev/null 2>&1
 282     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 283     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 284     raw=$fulldir/op.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 285     filtered=$fulldir/op.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 286
 287     echo "### xfs_logprint output ###" | tee $raw >$filtered
 288     _scratch_xfs_logprint -c  2>&1 \
 289     | tee -a $raw      \
 290     | _filter_logprint \
 291     | _filter_opnum    \
 292     >>$filtered
 293 }
 294
 295 # start at rec#2 "-s 2" so we skip over UMOUNT record which will always
 296 # be a 512b single header at mkfs time
 297 # and may not match with the FS mounted at a different LR size
 298 # => xlog_do_recovery_pass() can not handle the different hdr sizes
 299 #    it assumes them all to be the same between the start..finish
 300
 301 _print_transaction_inode()
 302 {
 303     _start=$1
 304     mkdir $fulldir >/dev/null 2>&1
 305     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 306     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 307     raw=$fulldir/trans_inode.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 308     filtered=$fulldir/trans_inode.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 309
 310     echo "### xfs_logprint -t -i -s START output ###" | tee $raw >$filtered
 311     _scratch_xfs_logprint -t -i -s $_start 2>&1 \
 312     | tee -a $raw      \
 313     | _filter_logprint \
 314     >>$filtered
 315 }
 316
 317 _print_transaction_buf()
 318 {
 319     _start=$1
 320     mkdir $fulldir >/dev/null 2>&1
 321     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 322     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 323     raw=$fulldir/trans_buf.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 324     filtered=$fulldir/trans_buf.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 325
 326     echo "### xfs_logprint -t -b -s START output ###" | tee $raw >$filtered
 327     _scratch_xfs_logprint -t -b -s $_start 2>&1 \
 328     | tee -a $raw      \
 329     | _filter_logprint \
 330     >>$filtered
 331 }
 332
 333 _mkfs_log()
 334 {
 335     # create the FS
 336     # mkfs options to append to log size otion can be specified ($*)
 337     export MKFS_OPTIONS="-l size=2000b -l lazy-count=1 $*"
 338     _full "mkfs"
 339     _scratch_mkfs_xfs >>$seqres.full 2>&1
 340     if [ $? -ne 0 ] ; then
 341         _echofull "Cannot mkfs for this test using option specified: $MKFS_OPTIONS"
 342         return 1
 343     fi
 344
 345     return 0
 346 }
 347
 348
 349 #
 350 # mount fs and create some log traffic
 351 #
 352 _create_log()
 353 {
 354     # mount the FS
 355     _full "mount"
 356     _try_scratch_mount >>$seqres.full 2>&1
 357     if [ $? -ne 0 ] ; then
 358         _echofull "mount failed: $MOUNT_OPTIONS"
 359         return 1
 360     fi
 361
 362     # generate some log traffic - but not too much - life gets a little
 363     # more complicated if the log wraps around. This traffic is
 364     # pretty much arbitary, but could probably be made better than this.
 365     touch $SCRATCH_MNT/{0,1,2,3,4,5,6,7,8,9}{0,1,2,3,4,5,6,7,8,9}
 366
 367     # unmount the FS
 368     _full "umount"
 369     _scratch_unmount >>$seqres.full 2>&1
 370     if [ $? -ne 0 ] ; then
 371         _echofull "umount failed"
 372         return 1
 373     fi
 374
 375     return 0
 376 }
 377
 378 #
 379 # mount fs and create some log traffic with sync'ing
 380 #
 381 _create_log_sync()
 382 {
 383     # mount the FS
 384     _full " mount"
 385     _try_scratch_mount >>$seqres.full 2>&1
 386     if [ $? -ne 0 ] ; then
 387         _echofull "mount failed: $MOUNT_OPTIONS"
 388         return 1
 389     fi
 390
 391     # generate some log traffic - but not too much
 392     # add some syncs to get the log flushed to disk
 393     for file in $SCRATCH_MNT/{0,1,2,3,4,5,6,7,8,9}{0,1,2,3,4,5,6,7,8,9}; do
 394         touch $file
 395         sync
 396     done
 397
 398     # unmount the FS
 399     _full "umount"
 400     _scratch_unmount >>$seqres.full 2>&1
 401     if [ $? -ne 0 ] ; then
 402         _echofull "umount failed"
 403         return 1
 404     fi
 405 }
 406
 407 _cmp_output()
 408 {
 409     echo "*** compare logprint: $1 with $2"
 410     if ! diff $1 $2 >/dev/null; then
 411         _fail "logprint output $1 differs to $2"
 412     fi
 413 }
 414
 415 #
 416 # Op data of different Log Record sizes will mean that data is
 417 # split at different points and in op printing it will not
 418 # try and decode the data which has been split up.
 419 # So we do a special diff processing to complain of differences
 420 # if no split is involved.
 421 #
 422 # Example diff with forms of:
 423 # "Left over region from split log item"
 424 # "Not printing rest of data"
 425 #
 426 #   2149c2149
 427 #   < Left over region from split log item
 428 #   ---
 429 #   > BUF DATA
 430 #   2888c2888,2889
 431 #   < INODE: #regs: 3 Not printing rest of data
 432 #   ---
 433 #   > INODE: #regs: 3 ino: 0x80 flags: 0x5 dsize: 16
 434 #   >  blkno: <BLKNO> len:<LEN> boff: <BOFF>
 435 #
 436 _process_op_diff()
 437 {
 438     $AWK_PROG <$1 '
 439         BEGIN { num_splits = 1; max_splits = 50 }
 440         /^[0-9]/ {
 441
 442                 # ensure a split happened in previous difference
 443                 if (num_splits < 1 || num_splits > max_splits) {
 444                         print num_splits, " split(s) found prior to diff cmd: ", $0
 445                         num_splits = 1 # shut-up end condition
 446                         exit 1
 447                 }
 448                 num_splits = 0
 449
 450                 next
 451         }
 452         /Left over region/ || /Not printing rest/ {
 453                 num_splits++
 454                 next
 455         }
 456         { next }
 457         END {
 458                 if (num_splits < 1 || num_splits > max_splits) {
 459                         print num_splits, " split(s) found prior to diff end"
 460                         exit 1
 461                 }
 462         }
 463     '
 464     return $?
 465 }
 466
 467 _cmp_op_output()
 468 {
 469     echo "*** compare logprint: $1 with $2"
 470
 471     diff $1 $2 >$filtered.diff
 472     if ! _process_op_diff $filtered.diff
 473     then
 474         _fail "logprint output $1 differs to $2 considering splits"
 475     fi
 476 }
 477
 478 # return xfs log version of device
 479 # e.g.
 480 #   _log_version /dev/dsk/dks0d1s4
 481 #
 482 _log_version()
 483 {
 484     _dev=$1
 485     vers=`xfs_db -c 'sb 0' -c 'p versionnum' -r $_dev | $AWK_PROG '{print $3}'`
 486     logver=`echo $vers | sed -e 's/0x[0-9a-f]\([0-9a-f]\)[0-9a-f][0-9a-f]/\1/'`
 487     if [ $logver = 4 -o $logver = 5 -o $logver = 6 -o $logver = 7 -o \
 488          $logver = c -o $logver = d -o $logver = e -o $logver = f ]; then
 489         echo 2
 490     else
 491         echo 1
 492     fi
 493 }
 494
 495 _require_v2log()
 496 {
 497     # test out mkfs to see if it supports "-l version=2"
 498     export MKFS_OPTIONS="-l version=2"
 499     if ! _scratch_mkfs_xfs >>$seqres.full 2>&1; then
 500         _notrun "mkfs does not support v2 logs"
 501     fi
 502
 503     # test out mount to see if it mounts a v2 log fs
 504     export MOUNT_OPTIONS="-o logbsize=32k"
 505     if ! _try_scratch_mount >>$seqres.full 2>&1; then
 506         _notrun "mount/kernel does not support v2 logs"
 507     fi
 508
 509     # check after unmount to see if it is clean
 510     # i.e. it is not a 6.5.25 buggy version checking kernel
 511     touch $SCRATCH_MNT/file
 512     _scratch_unmount >>$seqres.full 2>&1
 513     if _scratch_xfs_logprint -t | tee -a $seqres.full \
 514         | head | grep -q "<DIRTY>"; then
 515         _notrun "kernel does not support v2 logs"
 516     fi
 517
 518     # otherwise presume it does support v2 logs...:)
 519 }
 520
 521 _require_logstate()
 522 {
 523     case "$FSTYP" in
 524     xfs)
 525         if [ -z "$XFS_LOGPRINT_PROG" ]; then
 526             _notrun "This test requires xfs_logprint utility."
 527         fi
 528         ;;
 529     f2fs)
 530         if [ -z "$DUMP_F2FS_PROG" ]; then
 531             _notrun "This test requires dump.f2fs utility."
 532         fi
 533         ;;
 534     ext4)
 535         if [ -z "$DUMPE2FS_PROG" ]; then
 536                 _notrun "This test requires dumpe2fs utility."
 537         fi
 538         ;;
 539     *)
 540         _notrun "$FSTYP does not support log state probing."
 541         ;;
 542     esac
 543 }
 544
 545 _xfs_log_config()
 546 {
 547     echo "# mkfs-opt             mount-opt"
 548     echo "# ------------------------------"
 549     echo "  version=2            logbsize=32k"
 550     echo "  version=2,su=4096    logbsize=32k"
 551     echo "  version=2,su=32768   logbsize=32k"
 552     echo "  version=2,su=32768   logbsize=64k"
 553     echo "  version=2            logbsize=64k"
 554     echo "  version=2,su=64k     logbsize=64k"
 555     echo "  version=2            logbsize=128k"
 556     echo "  version=2,su=128k    logbsize=128k"
 557     echo "  version=2            logbsize=256k"
 558     echo "  version=2,su=256k    logbsize=256k"
 559 }
 560
 561 _f2fs_log_config()
 562 {
 563     echo "# mkfs-opt             mount-opt"
 564     echo "# ------------------------------"
 565     echo "  test1     active_logs=6,background_gc=off"
 566     echo "  test2     active_logs=6,background_gc=off,inline_data"
 567     echo "  test3     active_logs=6,background_gc=off,inline_dentry"
 568     echo "  test4     active_logs=6,background_gc=off,inline_data,inline_dentry"
 569     echo "  test5     active_logs=6,background_gc=off,disable_roll_forward"
 570     echo "  test6     active_logs=6,background_gc=off,discard,inline_data,inline_dentry"
 571     echo "  test7     active_logs=6,background_gc=on"
 572     echo "  test8     active_logs=6,background_gc=on,inline_data"
 573     echo "  test9     active_logs=6,background_gc=on,inline_data,inline_dentry"
 574     echo "  test10    active_logs=6,background_gc=on,discard,inline_data,inline_dentry"
 575 }
 576
 577 _ext4_log_config()
 578 {
 579     echo "# mkfs-opt             mount-opt"
 580     echo "# ------------------------------"
 581     echo "  /dev/null     data=writeback"
 582     echo "  /dev/null     data=ordered"
 583     echo "  /dev/null     data=journal"
 584     echo "  /dev/null     data=ordered,data_err=abort"
 585     echo "  /dev/null     data=writeback,nojournal_checksum"
 586     echo "  /dev/null     data=ordered,nojournal_checksum"
 587     echo "  /dev/null     data=journal,nojournal_checksum"
 588     echo "  /dev/null     data=ordered,data_err=abort,nojournal_checksum"
 589     echo "  /dev/null     data=writeback,journal_checksum"
 590     echo "  /dev/null     data=ordered,journal_checksum"
 591 }
 592
 593 _get_log_configs()
 594 {
 595     case "$FSTYP" in
 596     xfs)
 597         _xfs_log_config
 598         ;;
 599     f2fs)
 600         _f2fs_log_config
 601         ;;
 602     ext4)
 603         _ext4_log_config
 604         ;;
 605     *)
 606         _notrun "$FSTYP does not support log configs."
 607         ;;
 608     esac
 609 }
 610
 611 # make sure this script returns success
 612 /bin/true