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