Increased latency and timeouts due to vscan latency

Last updated
Save as PDF
Share
1. Share
2. Tweet
3. Share

Views:: 285

Visibility:: Public

Votes:: 0

Category:: ontap-9

Specialty:: NAS

Last Updated:

Applies to

ONTAP 9
VSCAN

Issue

Accessing any file is very slow
Increased latency is seen when copying files
EMS may logs show Nblade_CifsOperationTimedOut error :

kernel: Nblade_CifsOperationTimedOut_1:error]: params: {'remoteBladeID': '<id> (<node_name>)', 'cmdRestartCnt': '0', 'vserverId': '7', 'commandName': 'SMB2_COM_CREATE', 'isQosEnabled': 'QoS_disabled', 'lastSpinNpError': 'SPINNP_ERR_OFFBOX_VSCAN_REQD', 'localIpAddress': '10.xx.xx.xx', 'lastCsmError': 'CSM_OK', 'clientIpAddress': '10.xx.xx.xx', 'vserverName': '<svm_name>', 'suspensionCnt': '<count>', 'dsId': '<id>'}

Tue May 21 10:36:18 +0900 [node-01: kernel: ems.engine.suppressed:debug]: Event 'Nblade.CifsOperationTimedOut' suppressed 60 times in last 273 seconds.

VSCAN-EVENTS.XML may show scan-internal-error and scan-timedout messages
The performance archive shows high latency on the VSCAN server:

Cluster: cluster1 (4cfa91c5-761a-xxxxx-xxxxx-xxxxxxx) Node: node1 (4cfa91c5-761a-xxxxx-xxxxx-xxxxxxx) Time Range: 2024-07-21 18:00:00.999+00:00 - 2024-07-22 00:00:00.001+00:00 time interval offbox_vscan_server offbox_vscan_server offbox_vscan_server instance scan_latency scan_latency_base (us) ------------------------------------ ----------------------------------- ------------------- ------------------- 2024-07-21 18:31:18 - 18:36:18+00:00 svm1:10.x.x.1:node1 129298.60 5 2024-07-21 18:36:18 - 18:41:18+00:00 svm1:10.x.x.1:node1 121461.00 3 2024-07-21 18:41:18 - 18:46:18+00:00 svm1:10.x.x.1:node1 152285.50 2024-07-21 18:56:18 - 19:01:18+00:00 svm1:10.x.x.1:node1 243688.50 2024-07-21 19:01:18 - 19:06:18+00:00 svm1:10.x.x.1:node1 314138.00 2024-07-21 19:11:18 - 19:16:18+00:00 svm1:10.x.x.1:node1 141676.00 2024-07-21 19:16:18 - 19:21:18+00:00 svm1:10.x.x.1:node1 143551.20 5 2024-07-21 19:21:18 - 19:26:18+00:00 svm1:10.x.x.1:node1 138153.50 2024-07-21 19:26:18 - 19:31:18+00:00 svm1:10.x.x.1:node1 366887.00 3 2024-07-21 19:31:18 - 19:36:18+00:00 svm1:10.x.x.1:node1 1776264.29 7 2024-07-21 19:36:18 - 19:41:18+00:00 svm1:10.x.x.1:node1 390445.80 5 2024-07-21 19:41:18 - 19:46:18+00:00 svm1:10.x.x.1:node1 2185337.75 4 2024-07-21 19:46:18 - 19:51:18+00:00 svm1:10.x.x.1:node1 342919.09 11 2024-07-21 19:51:18 - 19:56:18+00:00 svm1:10.x.x.1:node1 566124.60 10

The qos statistics volume latency show shows high latency in the AVSCAN column

nas01::*> qos statistics volume latency show -volume vol1 -vserver svm1
Workload            ID    Latency    Network    Cluster       Data       Disk    QoS Max    QoS Min      NVRAM      Cloud  FlexCache    SM Sync         VA     AVSCAN
--------------- ------ ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
vol1-w..         19566     16.32s   117.00us   153.00us    70.00us        0ms        0ms        0ms        0ms        0ms        0ms        0ms        0ms     16.32s
-total-              -     9.39ms    31.00us        0ms    37.00us        0ms        0ms        0ms        0ms        0ms        0ms        0ms        0ms     9.32ms
vol1-w..         19566     22.77s   146.00us   198.00us    73.00us        0ms        0ms        0ms        0ms        0ms        0ms        0ms        0ms     22.77s