拡張ステータス0x16を持つEMSのWQEエラーが頻繁に発生する
環境
- NetApp FAS
- NetApp AFF
- Data ONTAP
問題
WQE Failure
Ext_Status 0x16 , Ext_Status 0x1d
Ext_Status 0x2
クラスタ内のすべてのノードのEMS
ログインASUPのストレージポートに and が記録されるというエラーが表示されます。-
Ext_Status 0x16
は、ホストイニシエータが現在のコマンドキューをクリアするために中止を送信したことを示します。これは必ずしも問題またはルート原因を特定するわけではなく、現象/副作用を特定するものです。 Ext_Status 0x1d
アウトオブオーダーフレーム配信があることを示します。
-
EMS
参照用のログスニペット:
fcp.io.status:debug]: STIO Adapter:2a IO WQE failure, Handle 0x0, Type 8, S_ID:abc VPI: 3, OX_ID: 3250, Status 0x3 Ext_Status 0x16
fcp.io.status:debug]:STIOアダプタ:2D IO WQE障害、ハンドル0x3、タイプ8、S_ID:31BDxx、VPI:278、OX_ID:80F、ステータス0x3 Ext_Status 0x1d
fcp.io.status:debug]: STIO Adapter:2d IO WQE failure, Handle 0x3, Type 8, S_ID: 31BDxx, VPI: 278, OX_ID: 552, Status 0x3 Ext_Status 0x2
-
EMS
ログインASUPにfound hung cmd
エラーが表示される。hung cmd with state=5
このエラーは、FCターゲットが書き込み要求を受け入れたあとにホストから何かが戻るのを待っていますが、想定タイムアウト値の範囲内に何も戻らなかったことを示しています。
Sat May 04 21:42:57 +0530 [Node1: fct_tpd_thread_1: fcp.io.status:debug]: STIO Adapter:11b, found hung cmd:0xfffff8182db43a60(state=5, flags=0x0, ctio_sent=1/1,RecvExAddr=0x2bee, OX_ID=0x2f7, RX_ID=0xffff,SID=0x51fxx, Cmd[8A], req_q_free:0)
- 受信電力と送信電力の両方が、ストレージ側で推奨される範囲内にあります。
Rx- 543.1 (uWatts)
Tx- 630.5 (uWatts)
- スイッチエンドでは 、
Porterrshow
ホストまたはストレージに接続されたポートのエラーを報告しません。
/fabos/cliexec/porterrshow :
frames enc crc crc too too bad enc disc link loss loss frjt fbsy c3timeout pcs uncor
tx rx in err g_eof shrt long eof out c3 fail sync sig tx rx err err
26: 1.0g 2.1g 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
31: 1.9g 906.0m 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
sfpshow
スイッチ側は 両方のポートに適しており、Tx電力とRx電力の両方が推奨範囲内にあります。- スイッチエンドの
Errdump
でframe timeout
イベントが報告され、同時にストレージエンドで報告されたSTIOエラーにも対応します。
注:次のインスタンス/例では、スイッチログはGMT、ストレージログはGMT+5:30
7:38 GMTです。3月16日は3月17日の午前1:08です。
- ログスニペットの終了を切り替えます-
2024/03/16-19:38:12, [AN-1014], 1865, FID 128, INFO, switch, Frame timeout detected, tx port 31 rx port 26, sid 51axx, did 51fxx, timestamp 2024-03-16 19:38:12
- ストレージエンドログスニペット-
Sun Mar 17 01:08:17 +0530 [Storage-01: fct_tpd_work_thread_0: fcp.io.status:debug]: STIO Adapter:11b IO WQE failure, Handle 0x1, Type 8, S_ID: 51Fxx, VPI: 275, OX_ID: 44D, Status 0x3 Ext_Status 0x16
Frame timeout
イベントは、フレーム(Rx)を受信したポートと、送信できないポート(Tx)を示します。- 上の例では、ポート31(Tx)が表示されています。ここでは、スイッチで
frame timeouts
報告されています。 - 送信電力は、ストレージとスイッチの両方で良好に見えます。そのため 、さらに分離するには、以下の手順を実行します。
- まず、スイッチ側のホストに接続されているポートのケーブルを 稼働中のスイッチポートにスワップし、問題が続くかどうかを確認します。
- 問題が続く場合は、スイッチSFPがTx電力が示すとおりに機能していることが証明されます。
- この投稿では、 エンドデバイスSFPや、エンドデバイスからスイッチへのケーブル接続など、他のハードウェアチェックに進みます。
上記の点に加えて、以下の問題も発生または発生する可能性があります。
- Active IQ Unified Managerイベント:
No Active Paths to Access LUN
The Network Interfaces that are used to access the LUN (mapped to initiator group xxxxx) hosted on SVM xxx are down
- 影響を受けるigroupによって使用されているいずれのNetAppポートでも、リンク関連の問題は確認されていません。
- Performance問題と
EMS
ログ内の複数のエントリの組み合わせ。 - VMが応答していない状態またはハング状態 であり、 エンドユーザはアプリケーションにアクセスできません。
FRAME DROP event has been observed
vmkernel
ログ
- Interoperability Matrix Toolの検証済みの設定で発生します。
EMS
ログでポートに接続されている物理SANスイッチで特定された物理レイヤの問題- タイムスタンプ中にエラーとパフォーマンスが発生しているファブリックまたはホストイニシエータの領域が特定されました
Credit loss events
show logging log a
およびshow process creditmon credit-loss-events
でホストに接続されているポートについて報告されます。Ciscoswitch# show logging log
:
2023 Sep 29 09:23:52 switch %LIBIFMGR-5-INTF_COUNTERS_CLEARED: Interface fc4/47, counters cleared by user
2023 Sep 29 09:46:23 switch %PMON-SLOT1-3-RISING_THRESHOLD_REACHED: TXWait has reached the rising threshold (port=fc1/4 [0x1003000], value=33) .
2023 Sep 29 09:46:25 switch %PMON-SLOT1-3-FALLING_THRESHOLD_REACHED: TXWait has reached the falling threshold (port=fc1/4 [0x1003000], value=0) .
2023 Sep 29 09:47:23 switch %PMON-SLOT1-3-FALLING_THRESHOLD_REACHED: Credit Loss Reco has reached the falling threshold (port=fc1/4 [0x1003000], value=0) .
2023 Sep 29 11:21:30 switch %PMON-SLOT1-3-RISING_THRESHOLD_REACHED: TXWait has reached the rising threshold (port=fc1/4 [0x1003000], value=68) .
2023 Sep 29 11:21:32 switch %PMON-SLOT1-3-FALLING_THRESHOLD_REACHED: TXWait has reached the falling threshold (port=fc1/4 [0x1003000], value=0)
2023 Sep 29 11:22:03 switch %PMON-SLOT1-3-RISING_THRESHOLD_REACHED: TX Discards has reached the rising threshold (port=fc1/4 [0x1003000], value=165) .
2023 Sep 29 11:22:22 switch %PMON-SLOT1-3-RISING_THRESHOLD_REACHED: Timeout Discards has reached the rising threshold (port=fc1/4 [0x1003000], value=165) .
2023 Sep 29 11:22:23 switch %PMON-SLOT1-3-RISING_THRESHOLD_REACHED: Credit Loss Reco has reached the rising threshold (port=fc1/4 [0x1003000], value=1) .
Ciscoswitch# show process creditmon credit-loss-events
Module: 01 Credit Loss Events: YES
----------------------------------------------------
| Interface | Total | Timestamp |
| | Events | |
----------------------------------------------------
| fc1/4 | 526 | 1. Fri Sep 29 12:21:34 2023 |
| | | 2. Fri Sep 29 11:21:30 2023 |
| | | 3. Fri Sep 29 09:46:23 2023 |
Overutilization
は 、ホストに接続されている複数のFポートで監視されます。
Congestion Summary...
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| | Tx Congestion problems |
| +--------------------------+--------------------------+--------------------------------+--------------------------------+--------------------------------+
| | Level 3 | Level 2 | Level 1.5 TxWait >= 30% | Level 1 TxWait < 30% | Tx Util >= 80% |
| +--------------------------+--------------------------+--------------------------------+--------------------------------+--------------------------------+
| | Mode E | Mode F | Other | Mode E | Mode F | Other | Mode E | Mode F | Other | Mode E | Mode F | Other | Mode E | Mode F | Other |
| Switchname | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports | Ports |
+ ------------------+--------+--------+--------+--------+--------+--------+----------+----------+----------+----------+----------+----------+----------+----------+----------+
| switch1 | No | Yes | Yes | No | Yes | Yes | No | Yes(63%) | No | No | Yes(29%) | No | No | Yes(86%) | No |
+-------------------+--------+--------+--------+--------+--------+--------+----------+----------+----------+----------+----------+----------+----------+----------+----------+
| switch2 | No | Yes | Yes | No | Yes | Yes | No | Yes(61%) | No | No | Yes(29%) | No | No | Yes(89%) | No |
+-------------------+--------+--------+--------+--------+--------+--------+--
-
TXwait congestion
ホストに接続されている複数のポートインターフェイス上のスイッチでレポートされます。
--------------------------------------------------------------------------------------------------------------
| Slowdrain level 1.5 problems found: Yes |
--------------------------------------------------------------------------------------------------------------
-------------------------------------------O B F L T x W a i t Congestion >= 30%-------------------------------------------
| Interface | Counter | Count | Delta | Timestamp |
----------------------------------------------------------------------------------------------------------------------------
| fc10/46 |TxWait Congestion 41% | 8sec | 3303328 | 2023/09/29 11:41:15 |
| fc10/46 | TxWait Congestion 40% | 8sec | 3226326 | 2023/09/29 11:41:35 |
| fc10/46 | TxWait Congestion 39% | 7sec | 3177619 | 2023/09/29 11:41:55 |
| fc10/46 | TxWait Congestion 32% | 6sec | 2565321 | 2023/09/29 15:32:56 |
TxWait
は、MDSがフレームの送信を待機する必要があることを意味します。これは、接続されたエンドデバイスからR_RDY
信号を受信しておらず、R_RDY
信号をMDSに送信していないため、エンドデバイスをチェックする必要があるためです。TxWait
ローカルスイッチがr_ready(B2Bクレジット)を2.5マイクロ秒待機するたびに増分します。このカウンタは20秒ごとに収集され、20秒で30%以上は収集されません。私たちの場合、20秒ごとにアラートを通過したくないし、リンクが遅いと判断するのは成熟した期間ではないので、300秒(5分)でポートモニタを70%に設定します。これは、より本物のアラートです。サービスプロバイダに報告できます。Slowdrain
ログにLR successful ,
と記載されていますこれは、エンドデバイス/HBA/ドライバ/ファームウェアが問題であり、エンド デバイスを調査する必要があることを意味します。
Switchname: hyd02-mds-switch1
--------------------------------------------------------------------------------------------------------------
| Slowdrain level 3 problems found: Yes |
--------------------------------------------------------------------------------------------------------------
-------------------------------------------C r e d i t L o s s R e c o v e r y -------------------------------------------
| Interface | Counter | Count | Delta | Timestamp |
----------------------------------------------------------------------------------------------------------------------------
| fc2/4 | F32_MAC_KLM_CNTR_CREDIT_LOSS(LR Successful) | 233 | 1 | 2023/09/29 04:02:11 |
| fc2/4 | F32_TMM_PORT_TIMEOUT_DROP | 30167 | 128 | |
| fc2/4 | F32_MAC_KLM_CNTR_CREDIT_LOSS(LR Successful) | 232 | 1 | 2023/09/29 04:00:30 |
| fc2/4 | F32_TMM_PORT_TIMEOUT_DROP | 30039 | 257 | |
| fc2/4 | F32_MAC_KLM_CNTR_CREDIT_LOSS(LR Successful) | 231 | 1 | 2023/09/29 03:40:07 |
| fc2/4 | F32_TMM_PORT_TIMEOUT_DROP | 29782 | 166 | |
| fc2/4 | F32_MAC_KLM_CNTR_CREDIT_LOSS(LR Successful) | 230 | 1 | 2023/09/29 03:38:06 |
| fc2/4 | F32_TMM_PORT_TIMEOUT_DROP