From: Brett Russ <bruss@netezza.com>
To: linux-raid@vger.kernel.org
Subject: Re: bug/race in md causing device to wedge in busy state
Date: Fri, 08 Jan 2010 10:18:50 -0500 [thread overview]
Message-ID: <hi7icq$s71$1@ger.gmane.org> (raw)
In-Reply-To: <20091224101256.39d2d09a@notabene>
On 12/23/2009 06:12 PM, Neil Brown wrote:
> Can you please see if the following patch fixes the problem.
>
> When an array wants to resync but is waiting for other arrays
> on the same devices to finish their resync, it does not abort the
> resync attempt properly when an error is reported.
> This should fix that.
Neil,
Sorry for the delay--holidays, etc. I tried the patch and, while the
newly added code is getting hit, I'm still hitting the issue. See below:
> mxmx# ./sim_md_busy.sh -dg1 /dev/sdg -dg2 /dev/sdp -df /dev/sdp -dr /dev/sdp -create -m bug3part 2>&1 | tee md_busy_run_bug3part.6
> mdadm --create /dev/md0 --force --run --level=1 --raid-devices=2 /dev/sdg1 /dev/sdp1 --assume-clean
> mdadm: /dev/sdg1 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: /dev/sdp1 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: array /dev/md0 started.
> mdadm --create /dev/md1 --force --run --level=1 --raid-devices=2 /dev/sdg3 /dev/sdp3 --assume-clean
> mdadm: /dev/sdg3 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: /dev/sdp3 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: array /dev/md1 started.
> mdadm --create /dev/md2 --force --run --level=1 --raid-devices=2 /dev/sdg4 /dev/sdp4 --assume-clean
> mdadm: /dev/sdg4 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: /dev/sdp4 appears to be part of a raid array:
> level=raid1 devices=2 ctime=Fri Jan 8 10:11:09 2010
> mdadm: array /dev/md2 started.
> mdadm --verbose --manage /dev/md0 --fail /dev/sdp1
> mdadm: set /dev/sdp1 faulty in /dev/md0
> mdadm --verbose --manage /dev/md0 --remove /dev/sdp1
> mdadm: hot removed /dev/sdp1
> mdadm --verbose --manage /dev/md1 --fail /dev/sdp3
> mdadm: set /dev/sdp3 faulty in /dev/md1
> mdadm --verbose --manage /dev/md1 --remove /dev/sdp3
> mdadm: hot removed /dev/sdp3
> mdadm --verbose --manage /dev/md2 --fail /dev/sdp4
> mdadm: set /dev/sdp4 faulty in /dev/md2
> mdadm --verbose --manage /dev/md2 --remove /dev/sdp4
> mdadm: hot removed /dev/sdp4
> mdadm --verbose --manage /dev/md0 --add /dev/sdp1
> mdadm: added /dev/sdp1
> mdadm --verbose --manage /dev/md1 --add /dev/sdp3
> mdadm: added /dev/sdp3
> mdadm --verbose --manage /dev/md2 --add /dev/sdp4
> mdadm: added /dev/sdp4
> Personalities : [raid1] [raid10]
> md2 : active raid1 sdp4[2] sdg4[0]
> 4200896 blocks [2/1] [U_]
> resync=DELAYED
>
> md1 : active raid1 sdp3[2] sdg3[0]
> 4200896 blocks [2/1] [U_]
> resync=DELAYED
>
> md0 : active raid1 sdp1[2] sdg1[0]
> 4200896 blocks [2/1] [U_]
> [>....................] recovery = 1.9% (80256/4200896) finish=0.8min speed=80256K/sec
>
> unused devices: <none>
> mdadm --verbose --manage /dev/md0 --fail /dev/sdp1
> mdadm: set /dev/sdp1 faulty in /dev/md0
> mdadm --verbose --manage /dev/md0 --remove /dev/sdp1
> mdadm: hot removed /dev/sdp1
> mdadm --verbose --manage /dev/md1 --fail /dev/sdp3
> mdadm: set /dev/sdp3 faulty in /dev/md1
> mdadm --verbose --manage /dev/md1 --remove /dev/sdp3
> mdadm: hot remove failed for /dev/sdp3: Device or resource busy
> mdadm: hot remove failed for /dev/sdp3: Device or resource busy
> mdadm: hot remove failed for /dev/sdp3: Device or resource busy
> ERROR: Command failed after 3 retries (mdadm --verbose --manage /dev/md1 --remove /dev/sdp3)
> mdadm --verbose --manage /dev/md2 --fail /dev/sdp4
> mdadm: set /dev/sdp4 faulty in /dev/md2
> mdadm --verbose --manage /dev/md2 --remove /dev/sdp4
> mdadm: hot removed /dev/sdp4
And the log from this run:
> Jan 8 10:11:41 mxmx user.notice root: chkpt
> Jan 8 10:11:46 mxmx user.info kernel: md: bind<sdg1>
> Jan 8 10:11:46 mxmx user.info kernel: md: bind<sdp1>
> Jan 8 10:11:46 mxmx user.info kernel: raid1: raid set md0 active with 2 out of 2 mirrors
> Jan 8 10:11:46 mxmx user.info kernel: md0: detected capacity change from 0 to 4301717504
> Jan 8 10:11:46 mxmx user.info kernel: md: bind<sdg3>
> Jan 8 10:11:46 mxmx user.info kernel: md: bind<sdp3>
> Jan 8 10:11:46 mxmx user.info kernel: raid1: raid set md1 active with 2 out of 2 mirrors
> Jan 8 10:11:46 mxmx user.info kernel: md1: detected capacity change from 0 to 4301717504
> Jan 8 10:11:47 mxmx user.info kernel: md: bind<sdg4>
> Jan 8 10:11:47 mxmx user.info kernel: md: bind<sdp4>
> Jan 8 10:11:47 mxmx user.info kernel: raid1: raid set md2 active with 2 out of 2 mirrors
> Jan 8 10:11:47 mxmx user.info kernel: md2: detected capacity change from 0 to 4301717504
> Jan 8 10:11:48 mxmx user.info kernel: md0:
> Jan 8 10:11:48 mxmx user.info kernel: unknown partition table
> Jan 8 10:11:48 mxmx user.alert kernel: raid1: Disk failure on sdp1, disabling device.
> Jan 8 10:11:48 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:11:48 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:48 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:48 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg1
> Jan 8 10:11:48 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp1
> Jan 8 10:11:48 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:48 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:48 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg1
> Jan 8 10:11:50 mxmx user.info kernel: md: unbind<sdp1>
> Jan 8 10:11:50 mxmx user.info kernel: md: export_rdev(sdp1)
> Jan 8 10:11:50 mxmx user.info kernel: md1:
> Jan 8 10:11:50 mxmx user.info kernel: unknown partition table
> Jan 8 10:11:50 mxmx user.alert kernel: raid1: Disk failure on sdp3, disabling device.
> Jan 8 10:11:50 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:11:50 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:50 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:50 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg3
> Jan 8 10:11:50 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp3
> Jan 8 10:11:50 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:50 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:50 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg3
> Jan 8 10:11:52 mxmx user.info kernel: md: unbind<sdp3>
> Jan 8 10:11:52 mxmx user.info kernel: md: export_rdev(sdp3)
> Jan 8 10:11:52 mxmx user.info kernel: md2:
> Jan 8 10:11:52 mxmx user.info kernel: unknown partition table
> Jan 8 10:11:52 mxmx user.alert kernel: raid1: Disk failure on sdp4, disabling device.
> Jan 8 10:11:52 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:11:52 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:52 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:52 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg4
> Jan 8 10:11:52 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp4
> Jan 8 10:11:52 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:52 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:52 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg4
> Jan 8 10:11:54 mxmx user.info kernel: md: unbind<sdp4>
> Jan 8 10:11:54 mxmx user.info kernel: md: export_rdev(sdp4)
> Jan 8 10:11:54 mxmx user.info kernel: md: bind<sdp1>
> Jan 8 10:11:54 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:54 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:54 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg1
> Jan 8 10:11:54 mxmx user.warn kernel: disk 1, wo:1, o:1, dev:sdp1
> Jan 8 10:11:54 mxmx user.info kernel: md: recovery of RAID array md0
> Jan 8 10:11:54 mxmx user.info kernel: md: minimum _guaranteed_ speed: 1000 KB/sec/disk.
> Jan 8 10:11:54 mxmx user.info kernel: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.
> Jan 8 10:11:54 mxmx user.info kernel: md: using 128k window, over a total of 4200896 blocks.
> Jan 8 10:11:54 mxmx user.info kernel: md: bind<sdp3>
> Jan 8 10:11:54 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:54 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:54 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg3
> Jan 8 10:11:54 mxmx user.warn kernel: disk 1, wo:1, o:1, dev:sdp3
> Jan 8 10:11:54 mxmx user.info kernel: md: delaying recovery of md1 until md0 has finished (they share one or more physical units)
> Jan 8 10:11:55 mxmx user.info kernel: md: bind<sdp4>
> Jan 8 10:11:55 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:55 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:55 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg4
> Jan 8 10:11:55 mxmx user.warn kernel: disk 1, wo:1, o:1, dev:sdp4
> Jan 8 10:11:55 mxmx user.info kernel: md: delaying recovery of md2 until md1 has finished (they share one or more physical units)
> Jan 8 10:11:56 mxmx user.alert kernel: raid1: Disk failure on sdp1, disabling device.
> Jan 8 10:11:56 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:11:56 mxmx user.info kernel: md: md0: recovery done.
> Jan 8 10:11:56 mxmx user.info kernel: md: delaying recovery of md2 until md1 has finished (they share one or more physical units)
> Jan 8 10:11:56 mxmx user.info kernel: md: delaying recovery of md1 until md2 has finished (they share one or more physical units)
> Jan 8 10:11:56 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:56 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:56 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg1
> Jan 8 10:11:56 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp1
> Jan 8 10:11:56 mxmx user.info kernel: md: recovery of RAID array md2
> Jan 8 10:11:56 mxmx user.info kernel: md: minimum _guaranteed_ speed: 1000 KB/sec/disk.
> Jan 8 10:11:56 mxmx user.info kernel: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for recovery.
> Jan 8 10:11:56 mxmx user.info kernel: md: using 128k window, over a total of 4200896 blocks.
> Jan 8 10:11:56 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:11:56 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:11:56 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg1
> Jan 8 10:11:58 mxmx user.info kernel: md: unbind<sdp1>
> Jan 8 10:11:58 mxmx user.info kernel: md: export_rdev(sdp1)
> Jan 8 10:11:58 mxmx user.alert kernel: raid1: Disk failure on sdp3, disabling device.
> Jan 8 10:11:58 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:12:00 mxmx user.warn kernel: md: cannot remove active disk sdp3 from md1 ...
> Jan 8 10:12:01 mxmx user.warn kernel: md: cannot remove active disk sdp3 from md1 ...
> Jan 8 10:12:02 mxmx user.warn kernel: md: cannot remove active disk sdp3 from md1 ...
> Jan 8 10:12:03 mxmx user.alert kernel: raid1: Disk failure on sdp4, disabling device.
> Jan 8 10:12:03 mxmx user.alert kernel: raid1: Operation continuing on 1 devices.
> Jan 8 10:12:03 mxmx user.info kernel: md: md2: recovery done.
> Jan 8 10:12:03 mxmx user.err kernel: md: running bug fix for md1
> Jan 8 10:12:03 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:12:03 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:12:03 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:12:03 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg4
> Jan 8 10:12:03 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp4
> Jan 8 10:12:03 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:12:03 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg3
> Jan 8 10:12:03 mxmx user.warn kernel: disk 1, wo:1, o:0, dev:sdp3
> Jan 8 10:12:03 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:12:03 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:12:03 mxmx user.warn kernel: RAID1 conf printout:
> Jan 8 10:12:03 mxmx user.warn kernel: --- wd:1 rd:2
> Jan 8 10:12:03 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg4
> Jan 8 10:12:03 mxmx user.warn kernel: disk 0, wo:0, o:1, dev:sdg3
> Jan 8 10:12:05 mxmx user.info kernel: md: unbind<sdp4>
> Jan 8 10:12:05 mxmx user.info kernel: md: export_rdev(sdp4)
Note the line "md: running bug fix for md1" at 10:12:03 which I added to
your patch inside the 'if' before the 'goto'. Looks like it hit that
code *after* the busy...
Thanks,
Brett
next prev parent reply other threads:[~2010-01-08 15:18 UTC|newest]
Thread overview: 5+ messages / expand[flat|nested] mbox.gz Atom feed top
2009-12-17 1:04 bug/race in md causing device to wedge in busy state Brett Russ
2009-12-22 21:48 ` Brett Russ
2009-12-23 23:12 ` Neil Brown
2010-01-08 15:18 ` Brett Russ [this message]
2010-01-29 14:50 ` Brett Russ
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to='hi7icq$s71$1@ger.gmane.org' \
--to=bruss@netezza.com \
--cc=linux-raid@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.