Re: [PATCH v3] xfstests: add test for xfs_repair progress reporting

From: Donald Douwsma <ddouwsma@redhat.com>
To: Eryu Guan <guaneryu@gmail.com>
Cc: linux-xfs@vger.kernel.org, fstests@vger.kernel.org,
	"Darrick J . Wong" <darrick.wong@oracle.com>,
	Eryu Guan <guan@eryu.me>, Zorro Lang <zlang@redhat.com>
Subject: Re: [PATCH v3] xfstests: add test for xfs_repair progress reporting
Date: Wed, 2 Sep 2020 19:04:27 +1000	[thread overview]
Message-ID: <eebaff94-d73d-2b0d-b433-dab3fb42602d@redhat.com> (raw)
In-Reply-To: <20200830155723.GA3853@desktop>

On 31/08/2020 01:57, Eryu Guan wrote:
> On Mon, Aug 17, 2020 at 05:53:13PM +1000, Donald Douwsma wrote:
>> xfs_repair's interval based progress has been broken for
>> some time, create a test based on dmdelay to stretch out
>> the time and use ag_stride to force parallelism.
>>
>> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
> 
> Thanks for the revision! But I'm still seeing the following diff with
> v5.9-rc2 kernel and latest xfsprogs for-next branch, which should
> contains the progress reporting patches I guess (HEAD is commit
> 2cf166bca8a2 ("xfs_db: set b_ops to NULL in set_cur for types without
> verifiers"))
> 
>  Format and populate
>  Introduce a dmdelay
>  Run repair
> + - #:#:#: Phase #: #% done - estimated remaining time 
>   - #:#:#: Phase #: #% done - estimated remaining time # minute, # second
>   - #:#:#: Phase #: elapsed time # second - processed # inodes per minute
>   - #:#:#: check for inodes claiming duplicate blocks - # of # inodes done

When testing this I only saw cases with minute(s) and second(s), but it turns
out that the duration function in xfs_repair/progress.c can produce an empty 
string or combinations of second, seconds, minute, minutes, day, days, week, 
or weeks.

This can affect the estimate string, but also the elapsed time like
    #:#:#: Phase #: #% done - estimated remaining time # second
    #:#:#: Phase #: elapsed time # second - processed # inodes per minute
    #:#:#: Phase #: elapsed time # seconds - processed # inodes per minute

I'll need to filter output from progress() specifically.

Thanks for pointing this out. 

Don

> 
>> ---
>> Changes since v2:
>> - Fix cleanup handling and function naming
>> - Added to auto group
>> Changes since v1:
>> - Use _scratch_xfs_repair
>> - Filter only repair output
>> - Make the filter more tolerant of whitespace and plurals
>> - Take golden output from 'xfs_repair: fix progress reporting'
>>
>>  tests/xfs/521     | 75 +++++++++++++++++++++++++++++++++++++++++++++++
>>  tests/xfs/521.out | 15 ++++++++++
>>  tests/xfs/group   |  1 +
>>  3 files changed, 91 insertions(+)
>>  create mode 100755 tests/xfs/521
>>  create mode 100644 tests/xfs/521.out
>>
>> diff --git a/tests/xfs/521 b/tests/xfs/521
>> new file mode 100755
>> index 00000000..c16c82bf
>> --- /dev/null
>> +++ b/tests/xfs/521
>> @@ -0,0 +1,75 @@
>> +#! /bin/bash
>> +# SPDX-License-Identifier: GPL-2.0
>> +# Copyright (c) 2020 Red Hat, Inc.  All Rights Reserved.
>> +#
>> +# FS QA Test 521
>> +#
>> +# Test xfs_repair's progress reporting
>> +#
>> +seq=`basename $0`
>> +seqres=$RESULT_DIR/$seq
>> +echo "QA output created by $seq"
>> +
>> +here=`pwd`
>> +tmp=/tmp/$$
>> +status=1	# failure is the default!
>> +trap "_cleanup; exit \$status" 0 1 2 3 15
>> +
>> +_cleanup()
>> +{
>> +	cd /
>> +	rm -f $tmp.*
>> +	_cleanup_delay > /dev/null 2>&1
>> +}
>> +
>> +# get standard environment, filters and checks
>> +. ./common/rc
>> +. ./common/filter
>> +. ./common/dmdelay
>> +. ./common/populate
>> +
>> +# remove previous $seqres.full before test
>> +rm -f $seqres.full
>> +
>> +# real QA test starts here
>> +
>> +# Modify as appropriate.
>> +_supported_fs xfs
>> +_supported_os Linux
>> +_require_scratch
>> +_require_dm_target delay
>> +
>> +# Filter output specific to the formatters in xfs_repair/progress.c
>> +# Ideally we'd like to see hits on anything that matches
>> +# awk '/{FMT/' repair/progress.c
>> +filter_repair()
>> +{
>> +	sed -ne '
>> +	s/[0-9]\+/#/g;
>> +	s/^\s\+/ /g;
>> +	s/\(second\|minute\)s/\1/g
>> +	/#:#:#:/p
>> +	'
>> +}
>> +
>> +echo "Format and populate"
>> +_scratch_populate_cached nofill > $seqres.full 2>&1
>> +
>> +echo "Introduce a dmdelay"
>> +_init_delay
>> +
>> +# Introduce a read I/O delay
>> +# The default in common/dmdelay is a bit too agressive
>> +BLK_DEV_SIZE=`blockdev --getsz $SCRATCH_DEV`
>> +DELAY_TABLE_RDELAY="0 $BLK_DEV_SIZE delay $SCRATCH_DEV 0 100 $SCRATCH_DEV 0 0"
>> +_load_delay_table $DELAY_READ
>> +
>> +echo "Run repair"
>> +SCRATCH_DEV=$DELAY_DEV _scratch_xfs_repair -o ag_stride=4 -t 1 2>&1 |
>> +        tee -a $seqres.full > $tmp.repair
>> +
>> +cat $tmp.repair | filter_repair | sort -u
>> +
>> +# success, all done
>> +status=0
>> +exit
>> diff --git a/tests/xfs/521.out b/tests/xfs/521.out
>> new file mode 100644
>> index 00000000..03337083
>> --- /dev/null
>> +++ b/tests/xfs/521.out
>> @@ -0,0 +1,15 @@
>> +QA output created by 521
>> +Format and populate
>> +Introduce a dmdelay
>> +Run repair
>> + - #:#:#: Phase #: #% done - estimated remaining time # minute, # second
>> + - #:#:#: Phase #: elapsed time # second - processed # inodes per minute
>> + - #:#:#: check for inodes claiming duplicate blocks - # of # inodes done
>> + - #:#:#: process known inodes and inode discovery - # of # inodes done
>> + - #:#:#: process newly discovered inodes - # of # allocation groups done
>> + - #:#:#: rebuild AG headers and trees - # of # allocation groups done
>> + - #:#:#: scanning agi unlinked lists - # of # allocation groups done
>> + - #:#:#: scanning filesystem freespace - # of # allocation groups done
>> + - #:#:#: setting up duplicate extent list - # of # allocation groups done
>> + - #:#:#: verify and correct link counts - # of # allocation groups done
>> + - #:#:#: zeroing log - # of # blocks done
>> diff --git a/tests/xfs/group b/tests/xfs/group
>> index ed0d389e..1c8ec5fa 100644
>> --- a/tests/xfs/group
>> +++ b/tests/xfs/group
>> @@ -517,3 +517,4 @@
>>  518 auto quick quota
>>  519 auto quick reflink
>>  520 auto quick reflink
>> +521 auto repair
>> -- 
>> 2.18.4
> 