Comment 30 for bug 1354114

Revision history for this message
Rafael David Tinoco (rafaeldtinoco) wrote :

# Precise failover test - removed 1 path during writes. failover after 10 seconds (iscsi timeout)

root@tryprecise:~# dd if=/dev/zero of=/dev/mapper/2luns0 bs=1M count=2000
2000+0 records in
2000+0 records out
2097152000 bytes (2.1 GB) copied, 137.125 s, 15.3 MB/s

ct 14 16:46:01 tryprecise kernel: [ 2000.944119] connection2:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295390028, last ping 4295391280, now 4295392532
Oct 14 16:46:01 tryprecise kernel: [ 2000.945011] connection2:0: detected conn error (1011)
Oct 14 16:46:01 tryprecise kernel: [ 2000.945014] connection6:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295390028, last ping 4295391280, now 4295392532
Oct 14 16:46:01 tryprecise kernel: [ 2000.945884] connection6:0: detected conn error (1011)
Oct 14 16:46:01 tryprecise iscsid: Kernel reported iSCSI connection 2:0 error (1011) state (3)
Oct 14 16:46:01 tryprecise iscsid: Kernel reported iSCSI connection 6:0 error (1011) state (3)
Oct 14 16:46:05 tryprecise kernel: [ 2005.232037] connection4:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295391098, last ping 4295392352, now 4295393604
Oct 14 16:46:05 tryprecise kernel: [ 2005.232944] connection4:0: detected conn error (1011)
Oct 14 16:46:06 tryprecise iscsid: Kernel reported iSCSI connection 4:0 error (1011) state (3)
Oct 14 16:46:37 tryprecise iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:47:38 iscsid: last message repeated 30 times
Oct 14 16:48:01 iscsid: last message repeated 11 times
Oct 14 16:48:01 tryprecise kernel: [ 2121.440066] session2: session recovery timed out after 120 secs
Oct 14 16:48:01 tryprecise kernel: [ 2121.440077] session6: session recovery timed out after 120 secs
Oct 14 16:48:02 tryprecise iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:48:05 iscsid: last message repeated 2 times
Oct 14 16:48:05 tryprecise kernel: [ 2125.792083] session4: session recovery timed out after 120 secs
Oct 14 16:48:06 tryprecise kernel: [ 2125.800111] sd 5:0:0:0: rejecting I/O to offline device
Oct 14 16:48:06 tryprecise kernel: [ 2125.800530] sd 5:0:0:0: [sdg] killing request
Oct 14 16:48:06 tryprecise kernel: [ 2125.800540] sd 5:0:0:0: rejecting I/O to offline device
...
Oct 14 16:48:06 tryprecise kernel: [ 2126.154444] Write(10): 2a 00 00 2d 3c 00 00 04 00 00
Oct 14 16:48:06 tryprecise kernel: [ 2126.154593] device-mapper: multipath: Failing path 8:112.
Oct 14 16:48:06 tryprecise multipathd: 2luns0: sdg - readsector0 checker reports path is down
Oct 14 16:48:06 tryprecise multipathd: checker failed path 8:96 in map 2luns0
Oct 14 16:48:06 tryprecise multipathd: 2luns0: remaining active paths: 1
Oct 14 16:48:06 tryprecise multipathd: 2luns1: sdh - readsector0 checker reports path is up
Oct 14 16:48:06 tryprecise multipathd: checker failed path 8:112 in map 2luns1
Oct 14 16:48:06 tryprecise multipathd: 2luns1: remaining active paths: 1
Oct 14 16:48:06 tryprecise multipathd: dm-4: add map (uevent)
Oct 14 16:48:06 tryprecise multipathd: dm-4: devmap already registered
Oct 14 16:48:06 tryprecise multipathd: dm-3: add map (uevent)
Oct 14 16:48:06 tryprecise multipathd: dm-3: devmap already registered
Oct 14 16:48:07 tryprecise multipathd: lun1: sdc - readsector0 checker reports path is up
Oct 14 16:48:07 tryprecise multipathd: checker failed path 8:32 in map lun1
Oct 14 16:48:07 tryprecise multipathd: lun1: remaining active paths: 1
Oct 14 16:48:07 tryprecise multipathd: lun2: sde - readsector0 checker reports path is up
Oct 14 16:48:07 tryprecise multipathd: checker failed path 8:64 in map lun2
Oct 14 16:48:07 tryprecise multipathd: lun2: remaining active paths: 1
Oct 14 16:48:07 tryprecise kernel: [ 2127.154798] device-mapper: multipath: Failing path 8:32.
Oct 14 16:48:07 tryprecise kernel: [ 2127.154849] device-mapper: multipath: Failing path 8:64.
Oct 14 16:48:07 tryprecise multipathd: dm-1: add map (uevent)
Oct 14 16:48:07 tryprecise multipathd: dm-1: devmap already registered
Oct 14 16:48:07 tryprecise multipathd: dm-2: add map (uevent)
Oct 14 16:48:07 tryprecise multipathd: dm-2: devmap already registered
Oct 14 16:48:08 tryprecise iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:48:09 iscsid: last message repeated 2 times
Oct 14 16:48:09 tryprecise multipathd: 2luns0: sdg - readsector0 checker reports path is down
Oct 14 16:48:09 tryprecise multipathd: 2luns1: sdh - readsector0 checker reports path is up
Oct 14 16:48:10 tryprecise multipathd: lun1: sdc - readsector0 checker reports path is up
Oct 14 16:48:10 tryprecise multipathd: lun2: sde - readsector0 checker reports path is up
Oct 14 16:48:12 tryprecise multipathd: 2luns0: sdg - readsector0 checker reports path is down
Oct 14 16:48:12 tryprecise multipathd: 2luns1: sdh - readsector0 checker reports path is up
Oct 14 16:48:13 tryprecise multipathd: lun1: sdc - readsector0 checker reports path is up
Oct 14 16:48:13 tryprecise multipathd: lun2: sde - readsector0 checker reports path is up
Oct 14 16:48:14 tryprecise iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:48:15 iscsid: last message repeated 2 times
Oct 14 16:48:15 tryprecise multipathd: 2luns0: sdg - readsector0 checker reports path is down
Oct 14 16:48:15 tryprecise multipathd: 2luns1: sdh - readsector0 checker reports path is up
Oct 14 16:48:16 tryprecise multipathd: lun1: sdc - readsector0 checker reports path is up
Oct 14 16:48:16 tryprecise multipathd: lun2: sde - readsector0 checker reports path is up
Oct 14 16:48:18 tryprecise multipathd: 2luns0: sdg - readsector0 checker reports path is down
Oct 14 16:48:18 tryprecise multipathd: 2luns1: sdh - readsector0 checker reports path is up
Oct 14 16:48:19 tryprecise multipathd: lun1: sdc - readsector0 checker reports path is up
Oct 14 16:48:19 tryprecise multipathd: lun2: sde - readsector0 checker reports path is up
Oct 14 16:48:20 tryprecise iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:48:21 iscsid: last message repeated 2 times
...