[PATCH 0/2] xfstests/xfsprogs xfs_repair progress reporting test

[PATCH 0/2] xfstests/xfsprogs xfs_repair progress reporting test

[Donald Douwsma]

A while ago I was working on a test for xfs_repair's progress reporting. Due to
some inconsistency in the the progress reporting output the test would
occasionally fail and was never merged.

https://lore.kernel.org/linux-xfs/eebaff94-d73d-2b0d-b433-dab3fb42602d@redhat.com/

This came back and bit me when I noticed it was still broken in a specific
downstream release.

While I could just filter the odd xfs repair output I think it makes sense to
try and make the xfs_repair more consistent. A delay of 38ms seems to hit this
regularly for me on a dual processor vm with the current fstests/common/populate.

- Don

Donald Douwsma (2):
  fstests: add test for xfs_repair progress reporting
  xfs_repair: always print an estimate when reporting progress

-- 
2.39.3

[PATCH v4] xfstests: add test for xfs_repair progress reporting

[Donald Douwsma]

Confirm that xfs_repair reports on its progress if -o ag_stride is
enabled.

Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
---
Changes since v3
- Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
- Shorten the delay, remove superfluous dm-delay parameters
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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
 tests/xfs/999.out | 15 +++++++++++
 2 files changed, 81 insertions(+)
 create mode 100755 tests/xfs/999
 create mode 100644 tests/xfs/999.out

diff --git a/tests/xfs/999 b/tests/xfs/999
new file mode 100755
index 00000000..9e799f66
--- /dev/null
+++ b/tests/xfs/999
@@ -0,0 +1,66 @@
+#! /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
+#
+. ./common/preamble
+_begin_fstest auto repair
+
+# Override the default cleanup function.
+_cleanup()
+{
+	cd /
+	rm -f $tmp.*
+	_cleanup_delay > /dev/null 2>&1
+}
+
+# Import common functions.
+. ./common/filter
+. ./common/dmdelay
+. ./common/populate
+
+# real QA test starts here
+
+# Modify as appropriate.
+_supported_fs xfs
+_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/' xfsprogs-dev/repair/progress.c
+filter_repair()
+{
+	sed -nre '
+	s/[0-9]+/#/g;
+	s/^\s+/ /g;
+	s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
+	/#:#:#:/p
+	'
+}
+
+echo "Format and populate"
+_scratch_populate_cached nofill > $seqres.full 2>&1
+
+echo "Introduce a dmdelay"
+_init_delay
+DELAY_MS=38
+
+# 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 $DELAY_MS"
+_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/999.out b/tests/xfs/999.out
new file mode 100644
index 00000000..e27534d8
--- /dev/null
+++ b/tests/xfs/999.out
@@ -0,0 +1,15 @@
+QA output created by 999
+Format and populate
+Introduce a dmdelay
+Run repair
+ - #:#:#: Phase #: #% done - estimated remaining time {progres}
+ - #:#:#: Phase #: elapsed time {progres} - 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
-- 
2.39.3

[PATCH] xfs_repair: always print an estimate when reporting progress

[Donald Douwsma]

If xfs_repair completes the work for a given phase while allocation
groups are still being processed the estimated time may be zero, when
this occures xfs_repair prints an incomplete string.

 # xfs_repair -o ag_stride=4 -t 1 /dev/sdc
 Phase 1 - find and verify superblock...
         - reporting progress in intervals of 1 second
 Phase 2 - using internal log
         - zero log...
         - 20:52:11: zeroing log - 0 of 2560 blocks done
         - 20:52:12: zeroing log - 2560 of 2560 blocks done
         - scan filesystem freespace and inode maps...
         - 20:52:12: scanning filesystem freespace - 3 of 4 allocation groups done
         - 20:52:13: scanning filesystem freespace - 4 of 4 allocation groups done
         - found root inode chunk
 Phase 3 - for each AG...
         - scan and clear agi unlinked lists...
         - 20:52:13: scanning agi unlinked lists - 4 of 4 allocation groups done
         - process known inodes and perform inode discovery...
         - agno = 0
         - 20:52:13: process known inodes and inode discovery - 3456 of 40448 inodes done
         - 20:52:14: process known inodes and inode discovery - 3456 of 40448 inodes done
         - 20:52:14: Phase 3: elapsed time 1 second - processed 207360 inodes per minute
         - 20:52:14: Phase 3: 8% done - estimated remaining time 10 seconds
         - 20:52:15: process known inodes and inode discovery - 3456 of 40448 inodes done
         - 20:52:15: Phase 3: elapsed time 2 seconds - processed 103680 inodes per minute
         - 20:52:15: Phase 3: 8% done - estimated remaining time 21 seconds
         - 20:52:16: process known inodes and inode discovery - 33088 of 40448 inodes done
         - 20:52:16: Phase 3: elapsed time 3 seconds - processed 661760 inodes per minute
         - 20:52:16: Phase 3: 81% done - estimated remaining time
         - agno = 1
 	...

Make this more consistent by printing 'estimated remaining time 0
seconds' if there is a 0 estimate.

Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
---
 repair/progress.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/repair/progress.c b/repair/progress.c
index f6c4d988..9fb6e3eb 100644
--- a/repair/progress.c
+++ b/repair/progress.c
@@ -501,6 +501,8 @@ duration(int length, char *buf)
 			strcat(buf, _(", "));
 		strcat(buf, temp);
 	}
+	if (!(weeks|days|hours|minutes|seconds))
+		sprintf(buf, _("0 seconds"));
 
 	return(buf);
 }
-- 
2.39.3

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

[Murphy Zhou]

Adding fstests

On Wed, May 31, 2023 at 2:50 PM Donald Douwsma <ddouwsma@redhat.com> wrote:
>
> Confirm that xfs_repair reports on its progress if -o ag_stride is
> enabled.
>
> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>

Ack.

Thanks,
> ---
> Changes since v3
> - Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
> - Shorten the delay, remove superfluous dm-delay parameters
> 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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
>  tests/xfs/999.out | 15 +++++++++++
>  2 files changed, 81 insertions(+)
>  create mode 100755 tests/xfs/999
>  create mode 100644 tests/xfs/999.out
>
> diff --git a/tests/xfs/999 b/tests/xfs/999
> new file mode 100755
> index 00000000..9e799f66
> --- /dev/null
> +++ b/tests/xfs/999
> @@ -0,0 +1,66 @@
> +#! /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
> +#
> +. ./common/preamble
> +_begin_fstest auto repair
> +
> +# Override the default cleanup function.
> +_cleanup()
> +{
> +       cd /
> +       rm -f $tmp.*
> +       _cleanup_delay > /dev/null 2>&1
> +}
> +
> +# Import common functions.
> +. ./common/filter
> +. ./common/dmdelay
> +. ./common/populate
> +
> +# real QA test starts here
> +
> +# Modify as appropriate.
> +_supported_fs xfs
> +_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/' xfsprogs-dev/repair/progress.c
> +filter_repair()
> +{
> +       sed -nre '
> +       s/[0-9]+/#/g;
> +       s/^\s+/ /g;
> +       s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
> +       /#:#:#:/p
> +       '
> +}
> +
> +echo "Format and populate"
> +_scratch_populate_cached nofill > $seqres.full 2>&1
> +
> +echo "Introduce a dmdelay"
> +_init_delay
> +DELAY_MS=38
> +
> +# 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 $DELAY_MS"
> +_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/999.out b/tests/xfs/999.out
> new file mode 100644
> index 00000000..e27534d8
> --- /dev/null
> +++ b/tests/xfs/999.out
> @@ -0,0 +1,15 @@
> +QA output created by 999
> +Format and populate
> +Introduce a dmdelay
> +Run repair
> + - #:#:#: Phase #: #% done - estimated remaining time {progres}
> + - #:#:#: Phase #: elapsed time {progres} - 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
> --
> 2.39.3
>

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

[Zorro Lang]

On Fri, Jun 09, 2023 at 09:50:26AM +0800, Murphy Zhou wrote:
> Adding fstests
> 
> On Wed, May 31, 2023 at 2:50 PM Donald Douwsma <ddouwsma@redhat.com> wrote:
> >
> > Confirm that xfs_repair reports on its progress if -o ag_stride is
> > enabled.
> >
> > Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
> 
> Ack.

Hi Donald,

That's weird, I never saw the original patch email, did I miss something?
Please send the original patch to fstests@ if you hope to get reviewing
and merging (if acked:)

Thanks,
Zorro

> 
> Thanks,
> > ---
> > Changes since v3
> > - Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
> > - Shorten the delay, remove superfluous dm-delay parameters
> > 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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
> >  tests/xfs/999.out | 15 +++++++++++
> >  2 files changed, 81 insertions(+)
> >  create mode 100755 tests/xfs/999
> >  create mode 100644 tests/xfs/999.out
> >
> > diff --git a/tests/xfs/999 b/tests/xfs/999
> > new file mode 100755
> > index 00000000..9e799f66
> > --- /dev/null
> > +++ b/tests/xfs/999
> > @@ -0,0 +1,66 @@
> > +#! /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
> > +#
> > +. ./common/preamble
> > +_begin_fstest auto repair
> > +
> > +# Override the default cleanup function.
> > +_cleanup()
> > +{
> > +       cd /
> > +       rm -f $tmp.*
> > +       _cleanup_delay > /dev/null 2>&1
> > +}
> > +
> > +# Import common functions.
> > +. ./common/filter
> > +. ./common/dmdelay
> > +. ./common/populate
> > +
> > +# real QA test starts here
> > +
> > +# Modify as appropriate.
> > +_supported_fs xfs
> > +_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/' xfsprogs-dev/repair/progress.c
> > +filter_repair()
> > +{
> > +       sed -nre '
> > +       s/[0-9]+/#/g;
> > +       s/^\s+/ /g;
> > +       s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
> > +       /#:#:#:/p
> > +       '
> > +}
> > +
> > +echo "Format and populate"
> > +_scratch_populate_cached nofill > $seqres.full 2>&1
> > +
> > +echo "Introduce a dmdelay"
> > +_init_delay
> > +DELAY_MS=38
> > +
> > +# 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 $DELAY_MS"
> > +_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/999.out b/tests/xfs/999.out
> > new file mode 100644
> > index 00000000..e27534d8
> > --- /dev/null
> > +++ b/tests/xfs/999.out
> > @@ -0,0 +1,15 @@
> > +QA output created by 999
> > +Format and populate
> > +Introduce a dmdelay
> > +Run repair
> > + - #:#:#: Phase #: #% done - estimated remaining time {progres}
> > + - #:#:#: Phase #: elapsed time {progres} - 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
> > --
> > 2.39.3
> >
> 

Re: [PATCH] xfs_repair: always print an estimate when reporting progress

[Darrick J. Wong]

On Wed, May 31, 2023 at 04:41:43PM +1000, Donald Douwsma wrote:
> If xfs_repair completes the work for a given phase while allocation
> groups are still being processed the estimated time may be zero, when
> this occures xfs_repair prints an incomplete string.
> 
>  # xfs_repair -o ag_stride=4 -t 1 /dev/sdc
>  Phase 1 - find and verify superblock...
>          - reporting progress in intervals of 1 second
>  Phase 2 - using internal log
>          - zero log...
>          - 20:52:11: zeroing log - 0 of 2560 blocks done
>          - 20:52:12: zeroing log - 2560 of 2560 blocks done
>          - scan filesystem freespace and inode maps...
>          - 20:52:12: scanning filesystem freespace - 3 of 4 allocation groups done
>          - 20:52:13: scanning filesystem freespace - 4 of 4 allocation groups done
>          - found root inode chunk
>  Phase 3 - for each AG...
>          - scan and clear agi unlinked lists...
>          - 20:52:13: scanning agi unlinked lists - 4 of 4 allocation groups done
>          - process known inodes and perform inode discovery...
>          - agno = 0
>          - 20:52:13: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:14: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:14: Phase 3: elapsed time 1 second - processed 207360 inodes per minute
>          - 20:52:14: Phase 3: 8% done - estimated remaining time 10 seconds
>          - 20:52:15: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:15: Phase 3: elapsed time 2 seconds - processed 103680 inodes per minute
>          - 20:52:15: Phase 3: 8% done - estimated remaining time 21 seconds
>          - 20:52:16: process known inodes and inode discovery - 33088 of 40448 inodes done
>          - 20:52:16: Phase 3: elapsed time 3 seconds - processed 661760 inodes per minute
>          - 20:52:16: Phase 3: 81% done - estimated remaining time
>          - agno = 1
>  	...
> 
> Make this more consistent by printing 'estimated remaining time 0
> seconds' if there is a 0 estimate.
> 
> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>

Reviewed-by: Darrick J. Wong <djwong@kernel.org>

--D

> ---
>  repair/progress.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/repair/progress.c b/repair/progress.c
> index f6c4d988..9fb6e3eb 100644
> --- a/repair/progress.c
> +++ b/repair/progress.c
> @@ -501,6 +501,8 @@ duration(int length, char *buf)
>  			strcat(buf, _(", "));
>  		strcat(buf, temp);
>  	}
> +	if (!(weeks|days|hours|minutes|seconds))
> +		sprintf(buf, _("0 seconds"));
>  
>  	return(buf);
>  }
> -- 
> 2.39.3
> 

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

[Darrick J. Wong]

Tests ought to be cc'd to fstests@vger.kernel.org.

On Wed, May 31, 2023 at 04:40:24PM +1000, Donald Douwsma wrote:
> Confirm that xfs_repair reports on its progress if -o ag_stride is
> enabled.
> 
> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
> ---
> Changes since v3
> - Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
> - Shorten the delay, remove superfluous dm-delay parameters
> 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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
>  tests/xfs/999.out | 15 +++++++++++
>  2 files changed, 81 insertions(+)
>  create mode 100755 tests/xfs/999
>  create mode 100644 tests/xfs/999.out
> 
> diff --git a/tests/xfs/999 b/tests/xfs/999
> new file mode 100755
> index 00000000..9e799f66
> --- /dev/null
> +++ b/tests/xfs/999
> @@ -0,0 +1,66 @@
> +#! /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
> +#
> +. ./common/preamble
> +_begin_fstest auto repair
> +
> +# Override the default cleanup function.
> +_cleanup()
> +{
> +	cd /
> +	rm -f $tmp.*
> +	_cleanup_delay > /dev/null 2>&1
> +}
> +
> +# Import common functions.
> +. ./common/filter
> +. ./common/dmdelay
> +. ./common/populate
> +
> +# real QA test starts here
> +
> +# Modify as appropriate.
> +_supported_fs xfs
> +_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/' xfsprogs-dev/repair/progress.c
> +filter_repair()
> +{
> +	sed -nre '
> +	s/[0-9]+/#/g;
> +	s/^\s+/ /g;
> +	s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
> +	/#:#:#:/p
> +	'
> +}
> +
> +echo "Format and populate"
> +_scratch_populate_cached nofill > $seqres.full 2>&1
> +
> +echo "Introduce a dmdelay"
> +_init_delay
> +DELAY_MS=38

I wonder if this is where _init_delay should gain a delay_ms argument?

_init_delay() {
	local delay_ms="${1:-10000}"

	...
	DELAY_TABLE_RDELAY="0 $BLK_DEV_SIZE delay $SCRATCH_DEV 0 $delay_ms $SCRATCH_DEV 0 0"
}


> +# 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 $DELAY_MS"
> +_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/999.out b/tests/xfs/999.out
> new file mode 100644
> index 00000000..e27534d8
> --- /dev/null
> +++ b/tests/xfs/999.out
> @@ -0,0 +1,15 @@
> +QA output created by 999
> +Format and populate
> +Introduce a dmdelay
> +Run repair
> + - #:#:#: Phase #: #% done - estimated remaining time {progres}
> + - #:#:#: Phase #: elapsed time {progres} - 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

Otherwise seems fine to me, assuming nothing goes nuts if rt devices or
whatever happen to be configured. ;)

--D

> -- 
> 2.39.3
> 

Re: [PATCH] xfs_repair: always print an estimate when reporting progress

[Bill O'Donnell]

On Wed, May 31, 2023 at 04:41:43PM +1000, Donald Douwsma wrote:
> If xfs_repair completes the work for a given phase while allocation
> groups are still being processed the estimated time may be zero, when
> this occures xfs_repair prints an incomplete string.
> 
>  # xfs_repair -o ag_stride=4 -t 1 /dev/sdc
>  Phase 1 - find and verify superblock...
>          - reporting progress in intervals of 1 second
>  Phase 2 - using internal log
>          - zero log...
>          - 20:52:11: zeroing log - 0 of 2560 blocks done
>          - 20:52:12: zeroing log - 2560 of 2560 blocks done
>          - scan filesystem freespace and inode maps...
>          - 20:52:12: scanning filesystem freespace - 3 of 4 allocation groups done
>          - 20:52:13: scanning filesystem freespace - 4 of 4 allocation groups done
>          - found root inode chunk
>  Phase 3 - for each AG...
>          - scan and clear agi unlinked lists...
>          - 20:52:13: scanning agi unlinked lists - 4 of 4 allocation groups done
>          - process known inodes and perform inode discovery...
>          - agno = 0
>          - 20:52:13: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:14: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:14: Phase 3: elapsed time 1 second - processed 207360 inodes per minute
>          - 20:52:14: Phase 3: 8% done - estimated remaining time 10 seconds
>          - 20:52:15: process known inodes and inode discovery - 3456 of 40448 inodes done
>          - 20:52:15: Phase 3: elapsed time 2 seconds - processed 103680 inodes per minute
>          - 20:52:15: Phase 3: 8% done - estimated remaining time 21 seconds
>          - 20:52:16: process known inodes and inode discovery - 33088 of 40448 inodes done
>          - 20:52:16: Phase 3: elapsed time 3 seconds - processed 661760 inodes per minute
>          - 20:52:16: Phase 3: 81% done - estimated remaining time
>          - agno = 1
>  	...
> 
> Make this more consistent by printing 'estimated remaining time 0
> seconds' if there is a 0 estimate.
> 
> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>

Looks fine.
Reviewed-by: Bill O'Donnell <bodonnel@redhat.com>

> ---
>  repair/progress.c | 2 ++
>  1 file changed, 2 insertions(+)
> 
> diff --git a/repair/progress.c b/repair/progress.c
> index f6c4d988..9fb6e3eb 100644
> --- a/repair/progress.c
> +++ b/repair/progress.c
> @@ -501,6 +501,8 @@ duration(int length, char *buf)
>  			strcat(buf, _(", "));
>  		strcat(buf, temp);
>  	}
> +	if (!(weeks|days|hours|minutes|seconds))
> +		sprintf(buf, _("0 seconds"));
>  
>  	return(buf);
>  }
> -- 
> 2.39.3
> 

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

[Zorro Lang]

On Fri, Jun 09, 2023 at 07:52:53AM -0700, Darrick J. Wong wrote:
> Tests ought to be cc'd to fstests@vger.kernel.org.

Thanks, I got this patch now :)

> 
> On Wed, May 31, 2023 at 04:40:24PM +1000, Donald Douwsma wrote:
> > Confirm that xfs_repair reports on its progress if -o ag_stride is
> > enabled.
> > 
> > Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
> > ---
> > Changes since v3
> > - Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
> > - Shorten the delay, remove superfluous dm-delay parameters
> > 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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
> >  tests/xfs/999.out | 15 +++++++++++
> >  2 files changed, 81 insertions(+)
> >  create mode 100755 tests/xfs/999
> >  create mode 100644 tests/xfs/999.out
> > 
> > diff --git a/tests/xfs/999 b/tests/xfs/999
> > new file mode 100755
> > index 00000000..9e799f66
> > --- /dev/null
> > +++ b/tests/xfs/999
> > @@ -0,0 +1,66 @@
> > +#! /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
> > +#
> > +. ./common/preamble
> > +_begin_fstest auto repair
> > +
> > +# Override the default cleanup function.
> > +_cleanup()
> > +{
> > +	cd /
> > +	rm -f $tmp.*
> > +	_cleanup_delay > /dev/null 2>&1
> > +}
> > +
> > +# Import common functions.
> > +. ./common/filter
> > +. ./common/dmdelay
> > +. ./common/populate
> > +
> > +# real QA test starts here
> > +
> > +# Modify as appropriate.
> > +_supported_fs xfs

As a regression test case, we need to point out that it's:
  _fixed_by_git_commit xfsprogs a4d94d6c30ac "xfs_repair: fix progress reporting"

Then due to it might fail without the other patch [1] (which has been reviewed),
so we'd better to point out that:

  _wants_git_commit xfsprogs xxxxxxxxxxxx \
          "xfs_repair: always print an estimate when reporting progress"

[1]
https://lore.kernel.org/linux-xfs/ZIM%2FKegChkoeTJE8@redhat.com/T/#u


> > +_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/' xfsprogs-dev/repair/progress.c
> > +filter_repair()
> > +{
> > +	sed -nre '
> > +	s/[0-9]+/#/g;
> > +	s/^\s+/ /g;
> > +	s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
> > +	/#:#:#:/p
> > +	'
> > +}
> > +
> > +echo "Format and populate"
> > +_scratch_populate_cached nofill > $seqres.full 2>&1
> > +
> > +echo "Introduce a dmdelay"
> > +_init_delay
> > +DELAY_MS=38
> 
> I wonder if this is where _init_delay should gain a delay_ms argument?
> 
> _init_delay() {
> 	local delay_ms="${1:-10000}"

Agree

> 
> 	...
> 	DELAY_TABLE_RDELAY="0 $BLK_DEV_SIZE delay $SCRATCH_DEV 0 $delay_ms $SCRATCH_DEV 0 0"
> }
> 
> 
> > +# 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 $DELAY_MS"
> > +_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

If the `sort -u` is necessary, how about only print the lines we realy care,
filter out all other lines?

Thanks,
Zorro

> > +
> > +# success, all done
> > +status=0
> > +exit
> > diff --git a/tests/xfs/999.out b/tests/xfs/999.out
> > new file mode 100644
> > index 00000000..e27534d8
> > --- /dev/null
> > +++ b/tests/xfs/999.out
> > @@ -0,0 +1,15 @@
> > +QA output created by 999
> > +Format and populate
> > +Introduce a dmdelay
> > +Run repair
> > + - #:#:#: Phase #: #% done - estimated remaining time {progres}
> > + - #:#:#: Phase #: elapsed time {progres} - 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
> 
> Otherwise seems fine to me, assuming nothing goes nuts if rt devices or
> whatever happen to be configured. ;)
> 
> --D
> 
> > -- 
> > 2.39.3
> > 
> 

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

[Donald Douwsma]

On 10/6/23 16:38, Zorro Lang wrote:
> On Fri, Jun 09, 2023 at 07:52:53AM -0700, Darrick J. Wong wrote:
>> Tests ought to be cc'd to fstests@vger.kernel.org.
> 
> Thanks, I got this patch now :)

Sorry Zorro, I'd meant to CC the cover letter and test to fstests.

> 
>>
>> On Wed, May 31, 2023 at 04:40:24PM +1000, Donald Douwsma wrote:
>>> Confirm that xfs_repair reports on its progress if -o ag_stride is
>>> enabled.
>>>
>>> Signed-off-by: Donald Douwsma <ddouwsma@redhat.com>
>>> ---
>>> Changes since v3
>>> - Rebase after tests/xfs/groups removal (tools/convert-group), drop _supported_os
>>> - Shorten the delay, remove superfluous dm-delay parameters
>>> 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/999     | 66 +++++++++++++++++++++++++++++++++++++++++++++++
>>>   tests/xfs/999.out | 15 +++++++++++
>>>   2 files changed, 81 insertions(+)
>>>   create mode 100755 tests/xfs/999
>>>   create mode 100644 tests/xfs/999.out
>>>
>>> diff --git a/tests/xfs/999 b/tests/xfs/999
>>> new file mode 100755
>>> index 00000000..9e799f66
>>> --- /dev/null
>>> +++ b/tests/xfs/999
>>> @@ -0,0 +1,66 @@
>>> +#! /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
>>> +#
>>> +. ./common/preamble
>>> +_begin_fstest auto repair
>>> +
>>> +# Override the default cleanup function.
>>> +_cleanup()
>>> +{
>>> +	cd /
>>> +	rm -f $tmp.*
>>> +	_cleanup_delay > /dev/null 2>&1
>>> +}
>>> +
>>> +# Import common functions.
>>> +. ./common/filter
>>> +. ./common/dmdelay
>>> +. ./common/populate
>>> +
>>> +# real QA test starts here
>>> +
>>> +# Modify as appropriate.
>>> +_supported_fs xfs
> 
> As a regression test case, we need to point out that it's:
>    _fixed_by_git_commit xfsprogs a4d94d6c30ac "xfs_repair: fix progress reporting"
> 

Will do.

> Then due to it might fail without the other patch [1] (which has been reviewed),
> so we'd better to point out that:
> 
>    _wants_git_commit xfsprogs xxxxxxxxxxxx \
>            "xfs_repair: always print an estimate when reporting progress"
> 
> [1]
> https://lore.kernel.org/linux-xfs/ZIM%2FKegChkoeTJE8@redhat.com/T/#u

I'll send a v5 to fstests and linux-xfs once the above is merged and I
can add the commit.

- Don

> 
> 
>>> +_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/' xfsprogs-dev/repair/progress.c
>>> +filter_repair()
>>> +{
>>> +	sed -nre '
>>> +	s/[0-9]+/#/g;
>>> +	s/^\s+/ /g;
>>> +	s/(# (week|day|hour|minute|second)s?(, )?)+/{progres}/g;
>>> +	/#:#:#:/p
>>> +	'
>>> +}
>>> +
>>> +echo "Format and populate"
>>> +_scratch_populate_cached nofill > $seqres.full 2>&1
>>> +
>>> +echo "Introduce a dmdelay"
>>> +_init_delay
>>> +DELAY_MS=38
>>
>> I wonder if this is where _init_delay should gain a delay_ms argument?
>>
>> _init_delay() {
>> 	local delay_ms="${1:-10000}"
> 
> Agree
> 
>>
>> 	...
>> 	DELAY_TABLE_RDELAY="0 $BLK_DEV_SIZE delay $SCRATCH_DEV 0 $delay_ms $SCRATCH_DEV 0 0"
>> }
>>
>>
>>> +# 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 $DELAY_MS"
>>> +_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
> 
> If the `sort -u` is necessary, how about only print the lines we realy care,
> filter out all other lines?
> 
> Thanks,
> Zorro
> 
>>> +
>>> +# success, all done
>>> +status=0
>>> +exit
>>> diff --git a/tests/xfs/999.out b/tests/xfs/999.out
>>> new file mode 100644
>>> index 00000000..e27534d8
>>> --- /dev/null
>>> +++ b/tests/xfs/999.out
>>> @@ -0,0 +1,15 @@
>>> +QA output created by 999
>>> +Format and populate
>>> +Introduce a dmdelay
>>> +Run repair
>>> + - #:#:#: Phase #: #% done - estimated remaining time {progres}
>>> + - #:#:#: Phase #: elapsed time {progres} - 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
>>
>> Otherwise seems fine to me, assuming nothing goes nuts if rt devices or
>> whatever happen to be configured. ;)
>>
>> --D
>>
>>> -- 
>>> 2.39.3
>>>
>>
>