common.log

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