common.log

   1 ##/bin/sh
   2 #
   3 # Copyright (c) 2000-2002 Silicon Graphics, Inc.  All Rights Reserved.
   4 #
   5 # common routines for log testing
   6 # Created by dxm@sgi.com & tes@sgi.com
   7 #
   8
   9 fulldir=$seq.fulldir
  10 rm -rf $fulldir
  11
  12 _cleanup_logfiles()
  13 {
  14     if [ $status -eq 0 ]; then
  15         # don't keep these files around unless something went wrong
  16         rm -rf $fulldir
  17     fi
  18 }
  19
  20 _full()
  21 {
  22     echo ""            >>$seq.full
  23     echo "*** $* ***"  >>$seq.full
  24     echo ""            >>$seq.full
  25 }
  26
  27 _echofull()
  28 {
  29     echo ""            | tee -a $seq.full
  30     echo "*** $* ***"  | tee -a $seq.full
  31     echo ""            | tee -a $seq.full
  32 }
  33
  34 # Handle the operations which get split over Log Record
  35 # boundaries.
  36 # Oper (379)..... flags: CONTINUE
  37 # ...
  38 # Oper (0)....... flags: WAS_CONT END
  39 #
  40 # or
  41 #
  42 # Oper (379)..... flags: none
  43 # ...
  44 # Oper (0)....... flags: none
  45 #
  46 _filter_opnum()
  47 {
  48     $AWK_PROG '
  49 BEGIN {
  50         debug = 0
  51         }
  52 /^Oper/ && debug {
  53             printf "line = %s\n", $0
  54         }
  55 /^Oper/ {
  56             was_cont = 0
  57         }
  58 /^Oper/ && /flags: CONTINUE/ {
  59             # this will be the first op of split region
  60             $9 = "none" # overwrite CONTINUE flags
  61             print
  62             print "Not printing rest"
  63             was_cont = 1
  64             next
  65         }
  66 /^Oper/ && /flags: WAS_CONT END/ {
  67             # this will be the last op of split region
  68             # skip over was-continued op
  69             # we assume there can be only 1
  70             was_cont = 1
  71             next
  72         }
  73 (was_cont == 1) {
  74             # skip over any continued op stuff
  75             next
  76         }
  77         {print}
  78     '
  79 }
  80
  81 #
  82 # Filter out things that can change
  83 # We have complexities which change when log is sync'ed at different
  84 # times.
  85 # Example1: DATA FORK EXTENTS
  86 # These will not show up if inode is sync'ed sooner
  87 #       /DATA FORK EXTENTS/d;
  88 #       /INODE:/s/flags:0x5/flags:0x1/g;
  89 # define XFS_ILOG_CORE   0x001   /* log standard inode fields */
  90 # define XFS_ILOG_DEXT   0x004   /* log i_df.if_extents */
  91 #
  92 #
  93
  94 _filter_logprint()
  95 {
  96     _fix_malloc |\
  97     sed '
  98         s/ver:[0-9]/ver:<VERS>/;
  99         s/version [0-9] format [0-9]/version <VERS> format <FORMAT>/;
 100         s/data device: 0x[0-9a-f][0-9a-f]*/data device: <DEVICE>/;
 101         s/log device: 0x[0-9a-f][0-9a-f]*/log device: <DEVICE>/;
 102         s/log file: \".*\"/log device: <DEVICE>/;
 103         s/daddr: [0-9][0-9]*/daddr: <DADDR>/;
 104         s/length: [0-9][0-9]*/length: <LENGTH>/;
 105         s/length: [0-9][0-9]*/length: <LENGTH>/;
 106         s/^cycle num overwrites: .*$/cycle num overwrites: <TIDS>/;
 107         s/tid: [0-9a-f][0-9a-f]*/tid: <TID>/;
 108         s/tid:0x[0-9a-f][0-9a-f]*/tid:<TID>/;
 109         s/q:0x[0-9a-f][0-9a-f]*/q:<Q>/;
 110         s/a:0x[0-9a-f][0-9a-f]*/a:<A>/g;
 111         s/blkno:0x[0-9a-f][0-9a-f]*/blkno:<BLKNO>/g;
 112         s/blkno: *[0-9][0-9]* (0x[0-9a-f]*)/blkno: <BLKNO> (<BLKNO>)/g;
 113         s/blkno: *[0-9][0-9]*/blkno: <BLKNO>/g;
 114         s/boff: [0-9][0-9]*/boff: <BOFF>/g;
 115         s/len: *[0-9][0-9]*/len:<LEN>/g;
 116         /BUF:/s/[       ]*flags:.*$//;
 117         /zeroed blocks/s/[0-9][0-9]*/<COUNT>/g;
 118         /cleared blocks/d;
 119         /log tail/s/[0-9][0-9]*/<COUNT>/g;
 120         s/atime:[0-9a-fx]*  *mtime:[0-9a-fx]*  *ctime:[0-9a-fx]*/atime:<TIME>  mtime:<TIME>  ctime:<TIME>/;
 121         s/atime 0x[0-9a-f]* mtime 0x[0-9a-f]* ctime 0x[0-9a-f]*/atime <TIME>  mtime <TIME>  ctime <TIME>/;
 122         s/block [0-9][0-9]*/block <BLOCK>/;
 123         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>/;
 124         s/sunit: *[0-9][0-9]*  *swidth: *[0-9][0-9]*/sunit:<SUNIT> swidth:<SWIDTH>/;
 125         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>/;
 126         s/^uuid: *[0-9a-f-][0-9a-f-]* *format: *.*$/uuid: <UUID> format: <FORMAT>/;
 127         /flushiter:/d;
 128         /version:/,/h_size:/d;
 129         /override tail/s/[0-9][0-9]*/<TAIL_BLK>/;
 130         /^---*/d;
 131         /^===*/d;
 132         /^~~~*/d;
 133         /extended-header/d;
 134         /LOG REC AT LSN/d;
 135         /DATA FORK EXTENTS/d;
 136         s/BUF: cnt:[1-9][0-9]* total:[1-9][0-9]*.*/BUF: cnt:C total:T/;
 137         s/INO: cnt:[1-9][0-9]* total:[1-9][0-9]*.*/INO: cnt:C total:T/;
 138         s/#regs: *[1-9][0-9]*/#regs:R/;
 139         /INODE:/s/flags:0x5/flags:0x1/g;
 140         s/Oper ([0-9][0-9]*)/Oper (OPNUM)/;
 141         /^[     ]*$/d;
 142         s/  */ /g;
 143         s/ $//;
 144         s/newino: 0x[0-9a-f]*$/newino: <INO>/g
 145         s/newino:0x[0-9a-f]*$/newino:<INO>/g
 146         s/ino: 0x[0-9a-f]* flags:/ino: <INO> flags:/g
 147         s/ino:0x[0-9a-f]* flags:/ino:<INO> flags:/g
 148         s/onlink:[0-9][0-9]*/onlink:<ONLINK>/;
 149         s/gen:-*[0-9][0-9]*/gen:<GEN>/;
 150         s/gen 0x[0-9a-f][0-9a-f]*/gen <GEN>/;
 151     '|\
 152     awk '
 153         # collapse BUF DATA group into 1 line
 154         # for Oper data this can be over separate operations...ughh
 155         /BUF DATA/ {
 156                 if (!buf_data) { # 1st one
 157                     if (oper) {
 158                         print oper
 159                         oper = 0
 160                     }
 161                     print
 162                 }
 163                 buf_data = 1
 164                 oper = 0 # wont need it now
 165                 next
 166         }
 167         /^Oper/ {
 168                 # store it as we dont know if 2nd BUF DATA is to follow
 169                 if (oper) {
 170                     print oper
 171                 }
 172                 oper = $0
 173                 next
 174         }
 175         /^TRANS/ && dummy_rec == 1 {
 176                 # start printing again - dummy transaction over
 177                 dummy_rec = 0
 178         }
 179         /DUMMY1/ {
 180                 # filter out dummy transactions
 181                 dummy_rec = 1
 182                 next
 183         }
 184         {
 185                 if (dummy_rec) {
 186                     next
 187                 }
 188                 buf_data = 0
 189                 if (oper) { # now we can print out oper
 190                     print oper
 191                     oper = 0
 192                 }
 193                 print
 194         }
 195     '
 196 }
 197
 198 _check_log()
 199 {
 200     _full "clean_log : xfs_logprint"
 201     _scratch_xfs_logprint -t | tee -a $seq.full \
 202         | head | grep -q "<CLEAN>" || _fail "DIRTY LOG"
 203 }
 204
 205 _print_logstate()
 206 {
 207     _scratch_xfs_logprint -t | tee -a $seq.full >$tmp.logprint
 208     if grep -q "<DIRTY>" $tmp.logprint; then
 209         echo "dirty log"
 210     fi
 211     if grep -q "<CLEAN>" $tmp.logprint; then
 212         echo "clean log"
 213     fi
 214 }
 215
 216 _print_operation()
 217 {
 218     mkdir $fulldir >/dev/null 2>&1
 219     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 220     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 221     raw=$fulldir/op.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 222     filtered=$fulldir/op.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 223
 224     echo "### xfs_logprint output ###" | tee $raw >$filtered
 225     _scratch_xfs_logprint -c  2>&1 \
 226     | tee -a $raw      \
 227     | _filter_logprint \
 228     | _filter_opnum    \
 229     >>$filtered
 230 }
 231
 232 # start at rec#2 "-s 2" so we skip over UMOUNT record which will always
 233 # be a 512b single header at mkfs time
 234 # and may not match with the FS mounted at a different LR size
 235 # => xlog_do_recovery_pass() can not handle the different hdr sizes
 236 #    it assumes them all to be the same between the start..finish
 237 # NB: On IRIX there is no UMOUNT record and so we could start from -s 0.
 238
 239 _print_transaction_inode()
 240 {
 241     _start=$1
 242     mkdir $fulldir >/dev/null 2>&1
 243     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 244     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 245     raw=$fulldir/trans_inode.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 246     filtered=$fulldir/trans_inode.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 247
 248     echo "### xfs_logprint -t -i -s START output ###" | tee $raw >$filtered
 249     _scratch_xfs_logprint -t -i -s $_start 2>&1 \
 250     | tee -a $raw      \
 251     | _filter_logprint \
 252     >>$filtered
 253 }
 254
 255 _print_transaction_buf()
 256 {
 257     _start=$1
 258     mkdir $fulldir >/dev/null 2>&1
 259     mntopt=`echo $MOUNT_OPTIONS | sed 's/ //g'`
 260     mkfsopt=`echo $MKFS_OPTIONS | sed 's/ //g'`
 261     raw=$fulldir/trans_buf.mnt$mntopt.mkfs$mkfsopt$sync_suffix.raw
 262     filtered=$fulldir/trans_buf.mnt$mntopt.mkfs$mkfsopt$sync_suffix.filtered
 263
 264     echo "### xfs_logprint -t -b -s START output ###" | tee $raw >$filtered
 265     _scratch_xfs_logprint -t -b -s $_start 2>&1 \
 266     | tee -a $raw      \
 267     | _filter_logprint \
 268     >>$filtered
 269 }
 270
 271 _mkfs_log()
 272 {
 273     # create the FS
 274     # mkfs options to append to log size otion can be specified ($*)
 275     export MKFS_OPTIONS="-l size=2000b $*"
 276     _full "mkfs"
 277     _scratch_mkfs_xfs >>$seq.full 2>&1
 278     if [ $? -ne 0 ] ; then
 279         _echofull "Cannot mkfs for this test using option specified: $MKFS_OPTIONS"
 280         return 1
 281     fi
 282
 283     return 0
 284 }
 285
 286
 287 #
 288 # mount fs and create some log traffic
 289 #
 290 _create_log()
 291 {
 292     # mount the FS
 293     _full "mount"
 294     _scratch_mount >>$seq.full 2>&1
 295     if [ $? -ne 0 ] ; then
 296         _echofull "mount failed: $MOUNT_OPTIONS"
 297         return 1
 298     fi
 299
 300     # generate some log traffic - but not too much - life gets a little
 301     # more complicated if the log wraps around. This traffic is
 302     # pretty much arbitary, but could probably be made better than this.
 303     touch $SCRATCH_MNT/{0,1,2,3,4,5,6,7,8,9}{0,1,2,3,4,5,6,7,8,9}
 304
 305     # unmount the FS
 306     _full "umount"
 307     umount $SCRATCH_DEV >>$seq.full 2>&1
 308     if [ $? -ne 0 ] ; then
 309         _echofull "umount failed"
 310         return 1
 311     fi
 312
 313     return 0
 314 }
 315
 316 #
 317 # mount fs and create some log traffic with sync'ing
 318 #
 319 _create_log_sync()
 320 {
 321     # mount the FS
 322     _full " mount"
 323     _scratch_mount >>$seq.full 2>&1
 324     if [ $? -ne 0 ] ; then
 325         _echofull "mount failed: $MOUNT_OPTIONS"
 326         return 1
 327     fi
 328
 329     # generate some log traffic - but not too much
 330     # add some syncs to get the log flushed to disk
 331     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
 332         touch $file
 333         sync
 334     done
 335
 336     # unmount the FS
 337     _full "umount"
 338     umount $SCRATCH_DEV >>$seq.full 2>&1
 339     if [ $? -ne 0 ] ; then
 340         _echofull "umount failed"
 341         return 1
 342     fi
 343 }
 344
 345 _cmp_output()
 346 {
 347     echo "*** compare logprint: $1 with $2"
 348     if ! diff $1 $2 >/dev/null; then
 349         _fail "logprint output $1 differs to $2"
 350     fi
 351 }
 352
 353 #
 354 # Op data of different Log Record sizes will mean that data is
 355 # split at different points and in op printing it will not
 356 # try and decode the data which has been split up.
 357 # So we do a special diff processing to complain of differences
 358 # if no split is involved.
 359 #
 360 # Example diff with forms of:
 361 # "Left over region from split log item"
 362 # "Not printing rest of data"
 363 #
 364 #   2149c2149
 365 #   < Left over region from split log item
 366 #   ---
 367 #   > BUF DATA
 368 #   2888c2888,2889
 369 #   < INODE: #regs: 3 Not printing rest of data
 370 #   ---
 371 #   > INODE: #regs: 3 ino: 0x80 flags: 0x5 dsize: 16
 372 #   >  blkno: <BLKNO> len:<LEN> boff: <BOFF>
 373 #
 374 _process_op_diff()
 375 {
 376     $AWK_PROG <$1 '
 377         BEGIN { num_splits = 1; max_splits = 50 }
 378         /^[0-9]/ {
 379
 380                 # ensure a split happened in previous difference
 381                 if (num_splits < 1 || num_splits > max_splits) {
 382                         print num_splits, " split(s) found prior to diff cmd: ", $0
 383                         num_splits = 1 # shut-up end condition
 384                         exit 1
 385                 }
 386                 num_splits = 0
 387
 388                 next
 389         }
 390         /Left over region/ || /Not printing rest/ {
 391                 num_splits++
 392                 next
 393         }
 394         { next }
 395         END {
 396                 if (num_splits < 1 || num_splits > max_splits) {
 397                         print num_splits, " split(s) found prior to diff end"
 398                         exit 1
 399                 }
 400         }
 401     '
 402     return $?
 403 }
 404
 405 _cmp_op_output()
 406 {
 407     echo "*** compare logprint: $1 with $2"
 408
 409     diff $1 $2 >$filtered.diff
 410     if ! _process_op_diff $filtered.diff
 411     then
 412         _fail "logprint output $1 differs to $2 considering splits"
 413     fi
 414 }
 415
 416 # return xfs log version of device
 417 # e.g.
 418 #   _log_version /dev/dsk/dks0d1s4
 419 #
 420 _log_version()
 421 {
 422     _dev=$1
 423     vers=`xfs_db -c 'sb 0' -c 'p versionnum' -r $_dev | $AWK_PROG '{print $3}'`
 424     logver=`echo $vers | sed -e 's/0x[0-9a-f]\([0-9a-f]\)[0-9a-f][0-9a-f]/\1/'`
 425     if [ $logver = 4 -o $logver = 5 -o $logver = 6 -o $logver = 7 -o \
 426          $logver = c -o $logver = d -o $logver = e -o $logver = f ]; then
 427         echo 2
 428     else
 429         echo 1
 430     fi
 431 }
 432
 433 _require_v2log()
 434 {
 435     # test out mkfs to see if it supports "-l version=2"
 436     export MKFS_OPTIONS="-l version=2"
 437     if ! _scratch_mkfs_xfs >>$seq.full 2>&1; then
 438         _notrun "mkfs does not support v2 logs"
 439     fi
 440
 441     # test out mount to see if it mounts a v2 log fs
 442     export MOUNT_OPTIONS="-o logbsize=32k"
 443     if ! _scratch_mount >>$seq.full 2>&1; then
 444         _notrun "mount/kernel does not support v2 logs"
 445     fi
 446
 447     # check after unmount to see if it is clean
 448     # i.e. it is not a 6.5.25 buggy version checking kernel
 449     touch $SCRATCH_MNT/file
 450     umount $SCRATCH_DEV >>$seq.full 2>&1
 451     if _scratch_xfs_logprint -t | tee -a $seq.full \
 452         | head | grep -q "<DIRTY>"; then
 453         _notrun "kernel does not support v2 logs"
 454     fi
 455
 456     # otherwise presume it does support v2 logs...:)
 457 }
 458
 459
 460 # make sure this script returns success
 461 /bin/true