Comment 31 for bug 1354114

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

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

root@trytrusty:~# 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, 139.481 s, 15.0 MB/s

Oct 14 16:50:29 trytrusty multipathd: 2luns0: remaining active paths: 2
Oct 14 16:50:29 trytrusty multipathd: 2luns1: sde - readsector0 checker reports path is up
Oct 14 16:50:29 trytrusty multipathd: 8:64: reinstated
Oct 14 16:50:29 trytrusty multipathd: 2luns1: remaining active paths: 2
Oct 14 16:50:29 trytrusty multipathd: lun1: sdf - readsector0 checker reports path is up
Oct 14 16:50:29 trytrusty multipathd: 8:80: reinstated
Oct 14 16:50:29 trytrusty multipathd: lun1: remaining active paths: 2
Oct 14 16:50:29 trytrusty multipathd: lun2: sdh - readsector0 checker reports path is up
Oct 14 16:50:29 trytrusty multipathd: 8:112: reinstated
Oct 14 16:50:29 trytrusty multipathd: lun2: remaining active paths: 2
Oct 14 16:51:12 trytrusty kernel: [ 2299.056036] connection4:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295464558, last ping 4295465809, now 4295467060
Oct 14 16:51:12 trytrusty kernel: [ 2299.056803] connection4:0: detected conn error (1011)
Oct 14 16:51:12 trytrusty kernel: [ 2299.056805] connection6:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295464558, last ping 4295465809, now 4295467060
Oct 14 16:51:12 trytrusty kernel: [ 2299.057604] connection6:0: detected conn error (1011)
Oct 14 16:51:13 trytrusty iscsid: Kernel reported iSCSI connection 4:0 error (1011 - ISCSI_ERR_CONN_FAILED: iSCSI connection failed) state (3)
Oct 14 16:51:13 trytrusty iscsid: Kernel reported iSCSI connection 6:0 error (1011 - ISCSI_ERR_CONN_FAILED: iSCSI connection failed) state (3)
Oct 14 16:51:17 trytrusty kernel: [ 2303.312139] connection2:0: ping timeout of 5 secs expired, recv timeout 5, last rx 4295465620, last ping 4295466871, now 4295468124
Oct 14 16:51:17 trytrusty kernel: [ 2303.313099] connection2:0: detected conn error (1011)
Oct 14 16:51:17 trytrusty iscsid: Kernel reported iSCSI connection 2:0 error (1011 - ISCSI_ERR_CONN_FAILED: iSCSI connection failed) state (3)
Oct 14 16:51:49 trytrusty iscsid: connect to 172.16.22.51:3260 failed (No route to host)
Oct 14 16:53:13 trytrusty kernel: [ 2419.680167] session4: session recovery timed out after 120 secs
Oct 14 16:53:13 trytrusty kernel: [ 2419.680179] session6: session recovery timed out after 120 secs
Oct 14 16:53:17 trytrusty kernel: [ 2423.776056] session2: session recovery timed out after 120 secs
Oct 14 16:53:18 trytrusty kernel: [ 2423.784028] sd 3:0:0:0: rejecting I/O to offline device
Oct 14 16:53:18 trytrusty kernel: [ 2423.784374] sd 3:0:0:0: [sdb] killing request
Oct 14 16:53:18 trytrusty kernel: [ 2423.784393] sd 3:0:0:0: rejecting I/O to offline device
Oct 14 16:53:18 trytrusty kernel: [ 2423.784764] sd 3:0:0:0: [sdb] killing request
Oct 14 16:53:18 trytrusty kernel: [ 2423.784769] sd 3:0:0:0: rejecting I/O to offline device
Oct 14 16:53:18 trytrusty kernel: [ 2423.784779] sd 3:0:0:0: [sdb] Unhandled error code
Oct 14 16:53:18 trytrusty kernel: [ 2423.784780] sd 3:0:0:0: [sdb]
Oct 14 16:53:18 trytrusty kernel: [ 2423.784781] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Oct 14 16:53:18 trytrusty kernel: [ 2423.784782] sd 3:0:0:0: [sdb] CDB:
Oct 14 16:53:18 trytrusty kernel: [ 2423.784786] Write(10): 2a 00 00 10 a4 00 00 04 00 00
Oct 14 16:53:18 trytrusty kernel: [ 2423.784787] end_request: I/O error, dev sdb, sector 1090560
Oct 14 16:53:18 trytrusty kernel: [ 2423.788016] sd 3:0:0:0: [sdb] killing request
Oct 14 16:53:18 trytrusty kernel: [ 2423.788016] sd 3:0:0:0: rejecting I/O to offline device
Oct 14 16:53:18 trytrusty kernel: [ 2423.788016] sd 3:0:0:0: [sdb] killing request
...
Oct 14 16:53:18 trytrusty multipathd: 2luns0: sdb - readsector0 checker reports path is down
Oct 14 16:53:18 trytrusty multipathd: checker failed path 8:16 in map 2luns0
Oct 14 16:53:18 trytrusty multipathd: 2luns0: remaining active paths: 1
Oct 14 16:53:18 trytrusty multipathd: 2luns1: sde - readsector0 checker reports path is up
Oct 14 16:53:18 trytrusty multipathd: checker failed path 8:64 in map 2luns1
Oct 14 16:53:18 trytrusty multipathd: 2luns1: remaining active paths: 1
Oct 14 16:53:18 trytrusty multipathd: lun1: sdf - readsector0 checker reports path is up
Oct 14 16:53:18 trytrusty multipathd: checker failed path 8:80 in map lun1
Oct 14 16:53:18 trytrusty multipathd: lun1: remaining active paths: 1
Oct 14 16:53:18 trytrusty multipathd: lun2: sdh - readsector0 checker reports path is up
Oct 14 16:53:18 trytrusty multipathd: checker failed path 8:112 in map lun2
Oct 14 16:53:18 trytrusty multipathd: lun2: remaining active paths: 1
...
Oct 14 16:54:24 trytrusty iscsid: connection4:0 is operational after recovery (29 attempts)
Oct 14 16:54:24 trytrusty iscsid: connection2:0 is operational after recovery (28 attempts)
Oct 14 16:54:24 trytrusty iscsid: connection6:0 is operational after recovery (29 attempts)
Oct 14 16:54:24 trytrusty multipathd: 2luns0: sdb - readsector0 checker reports path is up
Oct 14 16:54:24 trytrusty multipathd: 8:16: reinstated
Oct 14 16:54:24 trytrusty multipathd: 2luns0: remaining active paths: 2
Oct 14 16:54:24 trytrusty multipathd: 2luns1: sde - readsector0 checker reports path is up
Oct 14 16:54:24 trytrusty multipathd: 8:64: reinstated
Oct 14 16:54:24 trytrusty multipathd: 2luns1: remaining active paths: 2
Oct 14 16:54:24 trytrusty multipathd: lun1: sdf - readsector0 checker reports path is up
Oct 14 16:54:24 trytrusty multipathd: 8:80: reinstated
Oct 14 16:54:24 trytrusty multipathd: lun1: remaining active paths: 2
Oct 14 16:54:24 trytrusty multipathd: lun2: sdh - readsector0 checker reports path is up
Oct 14 16:54:24 trytrusty multipathd: 8:112: reinstated
Oct 14 16:54:24 trytrusty multipathd: lun2: remaining active paths: 2