メインコンテンツまでスキップ

非所有権の計画的テイクオーバーの際に iSCSI I/O が長時間再開されます LUN ノード

Views:
7
Visibility:
Public
Votes:
0
Category:
aff-series
Specialty:
san
Last Updated:

に適用されます

  • ASA AFF-A400
  • ONTAP 9.7P6
  • ESXi 6.5U2
  • iSCSIプロトコル
  • IO 再開時間( IORT )

問題

node01 が LUN を所有している。計画的なテイクオーバー / ギブバックでは異なる IORT が観察されます。

  • ノード 01 が停止し、ノード 02 によってテイクオーバーされたときに、 0 ~ 0 の IORT が表示されます。

Tue Dec 01 2020 14:24:50 +09:00 :: storage failover takeover -ofnode node01 :: Pending 
Tue Dec 01 2020 14:24:50 +09:00 :: storage failover takeover -ofnode node01 :: Success

- VMkernel ログ:

2020-12-01T05:25:00.901Z cpu160:66966)NMP: nmp_ThrottleLogForDevice:3616: Cmd 0x2a (0x439e42191f80, 87453) to dev "naa.600a098038314541795d512d55517135" on path "vmhba64:C1:T9:L0"Failed: H:0x0 D:0x2 P:0x0 Valid sense data: 0x60x2a0x6. Act:FAILOVER   
2020-12-01T05:25:00.901Z cpu160:66966)WARNING: NMP: nmp_DeviceRetryCommand:133: Device "naa.600a098038314541795d512d55517135": awaiting fast path state update for failover with I/O blocked. No prior reservation exists on the device.
2020-12-01T05:25:00.901Z cpu77:88091)WARNING: NMP: nmp_DeviceStartLoop:729: NMP Device "naa.600a098038314541795d512d55517135" is blocked. Not starting I/O from device.
2020-12-01T05:25:01.419Z cpu96:66654)WARNING: NMP: nmpDeviceAttemptFailover:640: Retry world failover device "naa.600a098038314541795d512d55517135" - issuing command 0x439e42191f80
2020-12-01T05:25:01.419Z cpu160:66966)NMP: nmpCompleteRetryForPath:327: Retry world recovered device "naa.600a098038314541795d512d55517135"
2020-12-01T05:25:54.418Z cpu48:66653)NMP: nmp_ResetDeviceLogThrottling:3458: last error status from device naa.600a098038314541795d512d55517135 repeated 3 times
2020-12-01T05:25:59.132Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba64:CH:0 T:9 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
2020-12-01T05:25:59.132Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000001 TARGET: iqn.1992-08.com.netapp:sn.1657b648180c11ebb333d039ea212a1e:vs.3 TPGT: 402 TSIH: 0]
2020-12-01T05:25:59.132Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 10.110.20.207:17081 R: 10.110.20.83:3260]
2020-12-01T05:25:59.888Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba64:CH:2 T:9 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
2020-12-01T05:25:59.888Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000007 TARGET: iqn.1992-08.com.netapp:sn.1657b648180c11ebb333d039ea212a1e:vs.3 TPGT: 404 TSIH: 0]
2020-12-01T05:25:59.888Z cpu137:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 10.110.20.207:41390 R: 10.110.20.85:3260]

  • ノード 02 が停止し、ノード 01 にテイクオーバーされたとき、 20 秒以下の IORT が表示されます。

Tue Dec 01 2020 14:35:45 +09:00 :: storage failover takeover -ofnode node02 :: Pending 
Tue Dec 01 2020 14:35:46 +09:00 :: storage failover takeover -ofnode node02 :: Success 

- VMkernel ログ:

2020-12-01T05:36:27.186Z cpu181:85966)HBX: 2958: 'NET-TEST': HB at offset 3145728 - Waiting for timed out HB:
2020-12-01T05:36:27.186Z cpu181:85966)  [HB state abcdef02 offset 3145728 gen 1163 stampUS 4313278449 uuid 5fc5c5e6-b5209e6a-89a8-98f2b3169c0c jrnl <FB 13> drv 24.81 lockImpl 4 ip 172.16.16.105]
2020-12-01T05:36:30.122Z cpu24:76866)HBX: 2958: 'NET-TEST': HB at offset 3145728 - Waiting for timed out HB:
2020-12-01T05:36:30.122Z cpu24:76866)  [HB state abcdef02 offset 3145728 gen 1163 stampUS 4313278449 uuid 5fc5c5e6-b5209e6a-89a8-98f2b3169c0c jrnl <FB 13> drv 24.81 lockImpl 4 ip 172.16.16.105]
2020-12-01T05:36:35.698Z cpu164:66418)WARNING: iscsi_vmk: iscsivmk_TaskMgmtIssue: vmhba64:CH:3 T:9 L:0 : Task mgmt "Abort Task" with itt=0x1b6476 (refITT=0x1b646d) timed out.
2020-12-01T05:36:35.698Z cpu164:66418)WARNING: ScsiPath: 8255: Set retry timeout for failed TaskMgmt abort for CmdSN  0x45abe8, status Failure, path vmhba64:C3:T9:L0
2020-12-01T05:36:36.700Z cpu20:65950)WARNING: iscsi_vmk: iscsivmk_TaskMgmtIssue: vmhba64:CH:1 T:9 L:0 : Task mgmt "Abort Task" with itt=0x1ebabe (refITT=0x1ebab8) timed out.
2020-12-01T05:36:37.188Z cpu181:85966)HBX: 2958: 'NET-TEST': HB at offset 3145728 - Waiting for timed out HB:
2020-12-01T05:36:37.188Z cpu181:85966)  [HB state abcdef02 offset 3145728 gen 1163 stampUS 4313278449 uuid 5fc5c5e6-b5209e6a-89a8-98f2b3169c0c jrnl <FB 13> drv 24.81 lockImpl 4 ip 172.16.16.105]
2020-12-01T05:36:43.912Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba64:CH:1 T:9 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
2020-12-01T05:36:43.912Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000006 TARGET: iqn.1992-08.com.netapp:sn.1657b648180c11ebb333d039ea212a1e:vs.3 TPGT: 405 TSIH: 0]
2020-12-01T05:36:43.912Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 10.110.20.207:56385 R: 10.110.20.86:3260]
2020-12-01T05:36:43.912Z cpu126:66991)NMP: nmp_ThrottleLogForDevice:3616: Cmd 0x2a (0x439e421f9000, 87453) to dev "naa.600a098038314541795d512d55517135" on path "vmhba64:C1:T9:L0"Failed: H:0x2 D:0x0 P:0x0 Invalid sense data: 0x00x00x0. Act:EVAL
2020-12-01T05:36:43.912Z cpu126:66991)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.600a098038314541795d512d55517135" state in doubt; requested fast path state update...
2020-12-01T05:36:43.912Z cpu126:66991)ScsiDeviceIO: 2980: Cmd(0x439e421f9000) 0x2a, CmdSN 0xd1 from world 87453 to dev "naa.600a098038314541795d512d55517135" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2020-12-01T05:36:43.912Z cpu126:65871)ScsiDeviceIO: 2980: Cmd(0x43a042d6ab80) 0x2a, CmdSN 0xf5 from world 88333 to dev "naa.600a098038314541795d512d55517135" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x94 0x43 0x0.
2020-12-01T05:36:43.912Z cpu126:65871)ScsiDeviceIO: 2980: Cmd(0x439a407a0940) 0x2a, CmdSN 0xee from world 86425 to dev "naa.600a098038314541795d512d55517135" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2020-12-01T05:36:44.668Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: vmhba64:CH:3 T:9 CN:0: iSCSI connection is being marked "OFFLINE" (Event:4)
2020-12-01T05:36:44.668Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Sess [ISID: 00023d000008 TARGET: iqn.1992-08.com.netapp:sn.1657b648180c11ebb333d039ea212a1e:vs.3 TPGT: 403 TSIH: 0]
2020-12-01T05:36:44.668Z cpu126:66991)WARNING: iscsi_vmk: iscsivmk_StopConnection: Conn [CID: 0 L: 10.110.20.207:35316 R: 10.110.20.84:3260]
2020-12-01T05:36:44.668Z cpu20:66417)WARNING: iscsi_vmk: iscsivmk_TaskMgmtIssue: vmhba64:CH:3 T:9 L:0 : Task mgmt "Abort Task" with itt=0x1b6478 (refITT=0x1b646d) timed out.
2020-12-01T05:36:44.668Z cpu126:65871)WARNING: NMP: nmp_DeviceRequestFastDeviceProbe:237: NMP device "naa.600a098038314541795d512d55517135" state in doubt; requested fast path state update...
2020-12-01T05:36:44.668Z cpu126:65871)ScsiDeviceIO: 2980: Cmd(0x43a042d95d00) 0x2a, CmdSN 0xc2 from world 88333 to dev "naa.600a098038314541795d512d55517135" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x94 0x43 0x0.
2020-12-01T05:36:44.668Z cpu126:65871)ScsiDeviceIO: 2980: Cmd(0x439c4737f7c0) 0x2a, CmdSN 0xd5 from world 86833 to dev "naa.600a098038314541795d512d55517135" failed H:0x2 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0.
2020-12-01T05:36:44.668Z cpu164:66418)NMP: nmp_ThrottleLogForDevice:3562: last error status from device naa.600a098038314541795d512d55517135 repeated 5 times
2020-12-01T05:36:44.668Z cpu164:66418)NMP: nmp_ThrottleLogForDevice:3616: Cmd 0x89 (0x439a407ee040, 65735) to dev "naa.600a098038314541795d512d55517135" on path "vmhba64:C3:T9:L0" Failed: H:0x5 D:0x0 P:0x0 Invalid sense data: 0x0 0x0 0x0. Act:EVAL
2020-12-01T05:36:44.668Z cpu164:66418)ScsiDeviceIO: 3015: Cmd(0x439a407d9040) 0xfe, CmdSN 0x45abe8 from world 65735 to dev "naa.600a098038314541795d512d55517135" failed H:0x5 D:0x0 P:0x0 Invalid sense data: 0x80 0x41 0x0.
2020-12-01T05:36:44.683Z cpu126:65871)ScsiDeviceIO: 2965: Cmd(0x43a042d95d00) 0x2a, CmdSN 0xc2 from world 88333 to dev "naa.600a098038314541795d512d55517135" failed H:0x8 D:0x0 P:0x0
2020-12-01T05:36:44.683Z cpu126:65871)ScsiDeviceIO: 2965: Cmd(0x439c4737f7c0) 0x2a, CmdSN 0xd5 from world 86833 to dev "naa.600a098038314541795d512d55517135" failed H:0x8 D:0x0 P:0x0
2020-12-01T05:36:44.771Z cpu2:65950)HBX: 283: 'NET-TEST': HB at offset 3145728 - Reclaimed heartbeat [Timeout]:
2020-12-01T05:36:44.771Z cpu2:65950)  [HB state abcdef02 offset 3145728 gen 1163 stampUS 4340353221 uuid 5fc5c5e6-b5209e6a-89a8-98f2b3169c0c jrnl <FB 13> drv 24.81 lockImpl 4 ip 172.16.16.105]

のとう

 

CUSTOMER EXCLUSIVE CONTENT

Registered NetApp customers get unlimited access to our dynamic Knowledge Base.

New authoritative content is published and updated each day by our team of experts.

Current Customer or Partner?

Sign In for unlimited access

New to NetApp?

Learn more about our award-winning Support