Re: [LKP] Re: [ext4] 21175ca434: mdadm-selftests.enchmarks/mdadm-selftests/tests/01r1fail.fail

From: Rong Chen
Date: Thu Apr 29 2021 - 03:44:50 EST




On 4/28/21 10:03 PM, Theodore Ts'o wrote:
(Hmm, why did you cc linux-km on this report? I would have thought
dm-devel would have made more sense?)

On Tue, Apr 27, 2021 at 04:15:39PM +0800, kernel test robot wrote:
FYI, we noticed the following commit (built with gcc-9):

commit: 21175ca434c5d49509b73cf473618b01b0b85437 ("ext4: make prefetch_block_bitmaps default")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master

in testcase: mdadm-selftests
version: mdadm-selftests-x86_64-5d518de-1_20201008
with following parameters:

disk: 1HDD
test_prefix: 01r1
ucode: 0x21
So this failure makes no sense to me. Looking at the kmesg failure
logs, it's failing in the md layer:

kern :info : [ 99.775514] md/raid1:md0: not clean -- starting background reconstruction
kern :info : [ 99.783372] md/raid1:md0: active with 3 out of 4 mirrors
kern :info : [ 99.789735] md0: detected capacity change from 0 to 37888
kern :info : [ 99.796216] md: resync of RAID array md0
kern :crit : [ 99.900450] md/raid1:md0: Disk failure on loop2, disabling device.
md/raid1:md0: Operation continuing on 2 devices.
kern :crit : [ 99.918281] md/raid1:md0: Disk failure on loop1, disabling device.
md/raid1:md0: Operation continuing on 1 devices.
kern :info : [ 100.835833] md: md0: resync interrupted.
kern :info : [ 101.852898] md: resync of RAID array md0
kern :info : [ 101.858347] md: md0: resync done.
user :notice: [ 102.109684] /lkp/benchmarks/mdadm-selftests/tests/01r1fail... FAILED - see /var/tmp/01r1fail.log and /var/tmp/fail01r1fail.log for details

The referenced commit just turns block bitmap prefetching in ext4.
This should not cause md to failure; if so, that's an md bug, not an
ext4 bug. There should not be anything that the file system is doing
that would cause the kernel to think there is a disk failure.

By the way, the reproduction instructions aren't working currently:

To reproduce:

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
This fails because lkp is trying to apply a patch which does not apply
with the current version of the md tools.

Hi Ted,

Thanks for the feedback, yes, there's patch already be merged into mdadm,
we have removed it from our code.


bin/lkp split-job --compatible job.yaml
bin/lkp run compatible-job.yaml
And the current versions lkp don't generate a compatible-job.yaml file
when you run "lkp split-job --compatable"; instead it generates a new
yaml file with a set of random characters to generate a unique name.
(What Multics parlance would be called a "shriek name"[1] :-)

We have updated the steps to avoid misunderstanding.


Since I was having trouble running the reproduction; could you send
the /var/tmp/*fail.logs so we could have a bit more insight what is
going on?

I attached the log file for your reference,
btw the test is from https://github.com/neilbrown/mdadm/blob/master/tests/01r1fail,
you may want to run it directly.

Best Regards,
Rong Chen


Thanks!

- Ted
_______________________________________________
LKP mailing list -- lkp@xxxxxxxxxxxx
To unsubscribe send an email to lkp-leave@xxxxxxxxxxxx

+ . /lkp/benchmarks/mdadm-selftests/tests/01r1fail
++ mdadm -CR /dev/md0 -l1 -n4 /dev/loop0 /dev/loop1 /dev/loop2 missing
++ rm -f /var/tmp/stderr
++ case $* in
++ case $* in
++ for args in $*
++ [[ -CR =~ /dev/ ]]
++ for args in $*
++ [[ /dev/md0 =~ /dev/ ]]
++ [[ /dev/md0 =~ md ]]
++ for args in $*
++ [[ -l1 =~ /dev/ ]]
++ for args in $*
++ [[ -n4 =~ /dev/ ]]
++ for args in $*
++ [[ /dev/loop0 =~ /dev/ ]]
++ [[ /dev/loop0 =~ md ]]
++ /lkp/benchmarks/mdadm-selftests/mdadm --zero /dev/loop0
mdadm: Unrecognised md component device - /dev/loop0
++ for args in $*
++ [[ /dev/loop1 =~ /dev/ ]]
++ [[ /dev/loop1 =~ md ]]
++ /lkp/benchmarks/mdadm-selftests/mdadm --zero /dev/loop1
mdadm: Unrecognised md component device - /dev/loop1
++ for args in $*
++ [[ /dev/loop2 =~ /dev/ ]]
++ [[ /dev/loop2 =~ md ]]
++ /lkp/benchmarks/mdadm-selftests/mdadm --zero /dev/loop2
mdadm: Unrecognised md component device - /dev/loop2
++ for args in $*
++ [[ missing =~ /dev/ ]]
++ /lkp/benchmarks/mdadm-selftests/mdadm --quiet -CR /dev/md0 -l1 -n4 /dev/loop0 /dev/loop1 /dev/loop2 missing --auto=yes
++ rv=0
++ case $* in
++ cat /var/tmp/stderr
++ return 0
++ check resync
++ case $1 in
++ cnt=5
++ grep -sq resync /proc/mdstat
++ mdadm /dev/md0 --fail /dev/loop2
++ rm -f /var/tmp/stderr
++ case $* in
++ case $* in
++ /lkp/benchmarks/mdadm-selftests/mdadm --quiet /dev/md0 --fail /dev/loop2
++ rv=0
++ case $* in
++ cat /var/tmp/stderr
++ return 0
++ check resync
++ case $1 in
++ cnt=5
++ grep -sq resync /proc/mdstat
++ mdadm /dev/md0 --fail /dev/loop1
++ rm -f /var/tmp/stderr
++ case $* in
++ case $* in
++ /lkp/benchmarks/mdadm-selftests/mdadm --quiet /dev/md0 --fail /dev/loop1
++ rv=0
++ case $* in
++ cat /var/tmp/stderr
++ return 0
++ sleep 1
++ check nosync
++ case $1 in
++ sleep 0.5
++ grep -sq -E '(resync|recovery|reshape) *=' /proc/mdstat
+++ sed '/^ *\([0-9]*\) \/ \1/d'
+++ grep / /sys/block/md0/md/sync_completed
++ incomplete='2432 / 37888'
++ '[' -n '2432 / 37888' ']'
++ die 'resync or recovery is happening!'
++ echo -e '\n\tERROR: resync or recovery is happening! \n'

ERROR: resync or recovery is happening!

++ save_log fail
++ status=fail
++ logfile=fail01r1fail.log
++ cat /var/tmp/stderr
++ cp /var/tmp/log /var/tmp/01r1fail.log
++ echo '## lkp-ivb-d04: saving dmesg.'
++ dmesg -c
++ echo '## lkp-ivb-d04: saving proc mdstat.'
++ cat /proc/mdstat
++ array=($(mdadm -Ds | cut -d' ' -f2))
+++ mdadm -Ds
+++ rm -f /var/tmp/stderr
+++ cut '-d ' -f2
+++ case $* in
+++ case $* in
+++ /lkp/benchmarks/mdadm-selftests/mdadm --quiet -Ds
+++ rv=0
+++ case $* in
+++ cat /var/tmp/stderr
+++ return 0
++ '[' fail == fail ']'
++ echo 'FAILED - see /var/tmp/01r1fail.log and /var/tmp/fail01r1fail.log for details'
FAILED - see /var/tmp/01r1fail.log and /var/tmp/fail01r1fail.log for details
++ '[' loop == lvm ']'
++ '[' loop == loop -o loop == disk ']'
++ '[' '!' -z /dev/md0 -a 1 -ge 1 ']'
++ echo '## lkp-ivb-d04: mdadm -D /dev/md0'
++ /lkp/benchmarks/mdadm-selftests/mdadm -D /dev/md0
++ cat /proc/mdstat
++ grep -q 'linear\|external'
++ md_disks=($($mdadm -D -Y ${array[@]} | grep "/dev/" | cut -d'=' -f2))
+++ /lkp/benchmarks/mdadm-selftests/mdadm -D -Y /dev/md0
+++ grep /dev/
+++ cut -d= -f2
++ cat /proc/mdstat
++ grep -q bitmap
++ '[' 1 -eq 0 ']'
++ exit 2