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