Bug 34357 - raidhotadd on multipath device fails already added devices (possible FS corruption)
raidhotadd on multipath device fails already added devices (possible FS corru...
Status: CLOSED NOTABUG
Product: Red Hat Linux
Classification: Retired
Component: kernel (Show other bugs)
7.1
i386 Linux
medium Severity medium
: ---
: ---
Assigned To: Doug Ledford
Brock Organ
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2001-04-02 12:04 EDT by Michael E Brown
Modified: 2007-04-18 12:32 EDT (History)
1 user (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2001-04-09 15:28:07 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Michael E Brown 2001-04-02 12:04:58 EDT
Due to Bugzilla #33278, I created a multipath array with one path, then
tried to hotadd the other path. This is the original raidtab:

# Sample raid-1 configuration
raiddev			/dev/md0
raid-level		multipath
nr-raid-disks		1
#nr-raid-disks		2
nr-spare-disks		0
chunk-size		4

device			/dev/sdb
raid-disk		0

#device			/dev/sdl
#raid-disk		1
#

Here is the kernel's tail of woe... (edited for brevity)

Apr  2 10:09:07 localhost kernel: bind<sdb,1>
Apr  2 10:09:07 localhost kernel: sdb's event counter: 00000000
Apr  2 10:09:07 localhost kernel: RAID level -4 does not need chunksize!
Continuing anyway.
Apr  2 10:09:07 localhost kernel: md0: max total readahead window set to
508k
Apr  2 10:09:07 localhost kernel: md0: 1 data-disks, max readahead per
data-disk: 508k
Apr  2 10:09:07 localhost kernel: multipath: device sdb operational as IO
path 0
Apr  2 10:09:07 localhost kernel: multipath: array md0 active with 1 out of
1 IO paths (0 spare IO paths)
Apr  2 10:09:07 localhost kernel: md: updating md0 RAID superblock on
device
Apr  2 10:09:07 localhost kernel: sdb [events: 00000001](write) sdb's sb
offset: 8539712
Apr  2 10:09:07 localhost kernel: .
Apr  2 10:09:33 localhost kernel: trying to hot-add sdl to md0 ... 
Apr  2 10:09:33 localhost kernel: bind<sdl,2>
Apr  2 10:09:33 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:33 localhost kernel:  --- wd:1 rd:1 nd:1
Apr  2 10:09:33 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdb
Apr  2 10:09:33 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:33 localhost kernel:  --- wd:1 rd:1 nd:2
Apr  2 10:09:33 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdb
Apr  2 10:09:33 localhost kernel:  disk1, s:1, o:0, n:1 rd:1 us:1 dev:sdl
Apr  2 10:09:33 localhost kernel: md: updating md0 RAID superblock on
device
Apr  2 10:09:33 localhost kernel: sdl [events: 00000002](write) sdl's sb
offset: 8539712
Apr  2 10:09:35 localhost kernel: Device 08:10 not ready.
Apr  2 10:09:35 localhost kernel:  I/O error: dev 08:10, sector 14945824
Apr  2 10:09:35 localhost kernel: multipath: IO failure on sdb, disabling
IO path. 
Apr  2 10:09:35 localhost kernel: ^IOperation continuing on 0 IO paths.
Apr  2 10:09:35 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:35 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:09:35 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdb
Apr  2 10:09:35 localhost kernel:  disk1, s:1, o:0, n:1 rd:1 us:1 dev:sdl
Apr  2 10:09:35 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:37 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:09:37 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdb
Apr  2 10:09:37 localhost kernel:  disk1, s:1, o:1, n:1 rd:1 us:1 dev:sdl
Apr  2 10:09:37 localhost kernel: got DISKOP_SPARE_WRITE err: 0.
(spare_faulty(): 0)
Apr  2 10:09:37 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:37 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:09:37 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdb
Apr  2 10:09:37 localhost kernel:  disk1, s:1, o:1, n:1 rd:1 us:1 dev:sdl
Apr  2 10:09:37 localhost kernel: MULTIPATH conf printout:
Apr  2 10:09:37 localhost kernel:  --- wd:1 rd:1 nd:2
Apr  2 10:09:37 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdl
Apr  2 10:09:37 localhost kernel:  disk1, s:0, o:0, n:1 rd:1 us:1 dev:sdb
Apr  2 10:09:37 localhost kernel: multipath: sdb: rescheduling block
14945824
Apr  2 10:09:37 localhost kernel: multipath: sdb: rescheduling block
14945826

The previous line repeats many, many times :-).   I was 'mke2fs /dev/md0'
during the hotadd.
After this, /dev/sdb was listed as (F) in /proc/mdstat :-(

I then tried to hotremove /dev/sdb and re-add it to the array. This is
where I got FS corruption:

Apr  2 10:23:11 localhost kernel: trying to remove sdb from md0 ... 
Apr  2 10:23:11 localhost kernel: MULTIPATH conf printout:
Apr  2 10:23:11 localhost kernel:  --- wd:1 rd:1 nd:2
Apr  2 10:23:11 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdl
Apr  2 10:23:11 localhost kernel:  disk1, s:0, o:0, n:1 rd:1 us:1 dev:sdb
Apr  2 10:23:11 localhost kernel: MULTIPATH conf printout:
Apr  2 10:23:11 localhost kernel:  --- wd:1 rd:1 nd:1
Apr  2 10:23:11 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdl
Apr  2 10:23:11 localhost kernel:  disk1, s:0, o:0, n:1 rd:1 us:0 dev:[dev
00:00]
Apr  2 10:23:11 localhost kernel: unbind<sdb,1>
Apr  2 10:23:11 localhost kernel: export_rdev(sdb)
Apr  2 10:23:11 localhost kernel: md: updating md0 RAID superblock on
device
Apr  2 10:23:11 localhost kernel: sdl [events: 00000004](write) sdl's sb
offset: 8539712
Apr  2 10:23:11 localhost kernel: .
Apr  2 10:24:25 localhost kernel: trying to hot-add sdb to md0 ... 
Apr  2 10:24:25 localhost kernel: bind<sdb,2>
Apr  2 10:24:25 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:25 localhost kernel:  --- wd:1 rd:1 nd:1
Apr  2 10:24:25 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdl
Apr  2 10:24:25 localhost kernel:  disk1, s:0, o:0, n:1 rd:1 us:0 dev:[dev
00:00]
Apr  2 10:24:25 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:25 localhost kernel:  --- wd:1 rd:1 nd:2
Apr  2 10:24:25 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdl
Apr  2 10:24:25 localhost kernel:  disk1, s:1, o:0, n:1 rd:1 us:1 dev:sdb
Apr  2 10:24:25 localhost kernel: md: updating md0 RAID superblock on
device
Apr  2 10:24:25 localhost kernel: sdb [events: 00000005](write) sdb's sb
offset: 8539712
Apr  2 10:24:27 localhost kernel: Device 08:b0 not ready.
Apr  2 10:24:27 localhost kernel:  I/O error: dev 08:b0, sector 1052912
Apr  2 10:24:27 localhost kernel: multipath: IO failure on sdl, disabling
IO path. 
Apr  2 10:24:27 localhost kernel: ^IOperation continuing on 0 IO paths.
Apr  2 10:24:27 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:27 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:24:27 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdl
Apr  2 10:24:27 localhost kernel:  disk1, s:1, o:0, n:1 rd:1 us:1 dev:sdb
Apr  2 10:24:27 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:27 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:24:27 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdl
Apr  2 10:24:27 localhost kernel:  disk1, s:1, o:1, n:1 rd:1 us:1 dev:sdb
Apr  2 10:24:27 localhost kernel: got DISKOP_SPARE_WRITE err: 0.
(spare_faulty(): 0)
Apr  2 10:24:27 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:27 localhost kernel:  --- wd:0 rd:1 nd:2
Apr  2 10:24:27 localhost kernel:  disk0, s:0, o:0, n:0 rd:0 us:1 dev:sdl
Apr  2 10:24:27 localhost kernel:  disk1, s:1, o:1, n:1 rd:1 us:1 dev:sdb
Apr  2 10:24:29 localhost kernel: MULTIPATH conf printout:
Apr  2 10:24:29 localhost kernel:  --- wd:1 rd:1 nd:2
Apr  2 10:24:29 localhost kernel:  disk0, s:0, o:1, n:0 rd:0 us:1 dev:sdb
Apr  2 10:24:29 localhost kernel:  disk1, s:0, o:0, n:1 rd:1 us:1 dev:sdl
Apr  2 10:24:29 localhost kernel: multipath: sdl: rescheduling block
1052912
Apr  2 10:24:29 localhost kernel: multipath: sdl: rescheduling block
1052920

 -- lines similar to the above line repeat several times --

-- Then these, several times --
Apr  2 10:24:31 localhost kernel: Device 08:b0 not ready.
Apr  2 10:24:31 localhost kernel:  I/O error: dev 08:b0, sector 1052976
Apr  2 10:24:31 localhost kernel: multipath: sdl: rescheduling block
1052976

-- Then this... (note the "mdb" ???)
Apr  2 10:24:34 localhost kernel: mdb: rescheduling block 792024
Apr  2 10:24:34 localhost kernel: multipath: only one IO path left and IO
error.
Apr  2 10:24:34 localhost kernel: multipath: sdb: rescheduling block 792032

-- A while later...
Apr  2 10:24:43 localhost kernel: scsi2 channel 0 : resetting for second
half of retries.
Apr  2 10:24:43 localhost kernel: SCSI bus is being reset for host 2
channel 0.
Apr  2 10:24:43 localhost kernel: scsi(2:0:0:0): LOOP RESET ISSUED.
Apr  2 10:24:43 localhost kernel: SCSI disk error : host 2 channel 0 id 0
lun 0 return code = 25050000
Apr  2 10:24:43 localhost kernel:  I/O error: dev 08:10, sector 793072
Apr  2 10:24:43 localhost kernel: multipath: only one IO path left and IO
error.
Apr  2 10:24:43 localhost kernel: multipath: sdb: rescheduling block 793072
Apr  2 10:24:43 localhost kernel: SCSI disk error : host 2 channel 0 id 0
lun 0 return code = 25050000
Apr  2 10:24:43 localhost kernel:  I/O error: dev 08:10, sector 793136
Apr  2 10:24:43 localhost kernel: multipath: only one IO path left and IO
error.
Apr  2 10:24:43 localhost kernel: multipath: sdb: rescheduling block 793136
Apr  2 10:24:43 localhost kernel: scsi2: device driver called scsi_done()
for a synchronous reset.


-- Later...
Apr  2 10:24:43 localhost kernel: scsi2: Topology - (F_Port), Host Loop
addres  0xffff
Apr  2 10:24:43 localhost kernel: (skipping faulty (skipping alias sdl )
Apr  2 10:24:43 localhost kernel: .
Apr  2 10:24:43 localhost kernel: multipath: sdb: redirecting sector
1052912 to another IO path
Apr  2 10:24:43 localhost kernel: multipath: sdb: redirecting sector
1052920 to another IO path

-- Later...  
Apr  2 10:24:44 localhost kernel: multipath: sdb: unrecoverable IO read
error for block 7345344
Apr  2 10:24:44 localhost kernel: multipath: sdb: unrecoverable IO read
error for block 7345400
Apr  2 10:24:44 localhost kernel: multipath: sdb: unrecoverable IO read
error for block 7345440
Apr  2 10:24:44 localhost kernel: multipath: sdb: unrecoverable IO read
error for block 7345544


-- Later...
Apr  2 10:24:46 localhost kernel: attempt to access beyond end of device
Apr  2 10:24:46 localhost kernel: 09:00: rw=0, want=982245324,
limit=8539712
Apr  2 10:24:46 localhost kernel: attempt to access beyond end of device
Apr  2 10:24:46 localhost kernel: 09:00: rw=0, want=191067864,
limit=8539712
Apr  2 10:24:46 localhost kernel: attempt to access beyond end of device


-- And Finally...
Apr  2 10:25:50 localhost kernel: e_blocks: Freeing blocks not in datazone
- block = 4140306265, count = 1
Apr  2 10:25:50 localhost kernel: EXT2-fs error (device md(9,0)):
ext2_free_blocks: Freeing blocks not in datazone - block = 3652435245,
count = 1
Apr  2 10:25:50 localhost kernel: EXT2-fs error (device md(9,0)):
ext2_free_blocks: Freeing blocks not in datazone - block = 2720411960,
count = 1
Apr  2 10:25:50 localhost kernel: EXT2-fs error (device md(9,0)):
ext2_free_blocks: Freeing blocks not in datazone - block = 3784322288,
count = 1
Comment 1 Arjan van de Ven 2001-04-07 18:40:46 EDT
Last part is generic corruption, but before that looks
specific to multipath.  Doug?
Comment 2 Doug Ledford 2001-04-08 14:20:01 EDT
This actually looks like a bug in the disk firmware (or chassis firmware as the
case may be).  The report looks like as soon as you touch the secondary path
(when you write the new SB to the freshly added spare path), the primary path
returns an I/O error.  It would seem the disk chassis isn't configured to allow
simultaneous access or something like that.  Testing here on real disks (Seagate
FC disks with multiple paths to the disks) doesn't exhibit any I/O errors when
writing to both paths at the same time.  This theory is further bolstered by the
fact that the last set of sectors to get an I/O error weren't anywhere near the
disk SB, but were in the middle of the disk, indicating that when we wrote the
superblock on the new path, it interferred with I/O on the old path.  I would
write this up likely as a hardware bug.
Comment 3 Michael E Brown 2001-04-09 11:51:02 EDT
You are correct that the hardware is generating an error :-) This points out a
design issue with the current code. You cannot always assume that you can send
I/O down both paths of a device at the same time. The device I am testing
against in my lab (PV650) has to do an internal failover from controller to
controller in order to send IO to the alternate path. Trying to write
information to the raid superblock on the alternate path while doing heavy IO to
the primary path is a no-no. 

  Is it possible to modify the raidtools to write the updated superblock
information on the primary (active) path? This will prevent this problem, and
allow us to support devices that don't have full active/active channel support.
Or is it possible to use a command-line option to tell the raidtools to write
the superblock using another path?

BTW, this is the only device that this will happen on that I am aware of at this
time. The PV660 supports full active-active paths. I've just tested this in the
SAN lab, and raidhotadd/remove work just fine there.

Note You need to log in before you can comment on or make changes to this bug.