Cifs share access is very slow due to high load on vscan server
Applies to
- ONTAP 9 and later
- CIFS
- Vscan
Issue
- While accessing CIFS shares the response is very slow when vscan is enabled.
- Noticed below error in ems logs:
Wed Jul 26 20:00:45 +0900 [node1: kernel: Nblade_CifsOperationTimedOut_1:error]: params: {'remoteBladeID': '15b42a5c-5661-11e9-b5be-00a098f0b7e6 (node1)', 'cmdRestartCnt': '0', 'vserverId': '5', 'commandName': 'SMB2_COM_CREATE', 'isQosEnabled': 'QoS_disabled', 'lastSpinNpError': 'SPINNP_ERR_OFFBOX_VSCAN_REQD', 'localIpAddress': '10.xx.x.xxx', 'lastCsmError': 'CSM_OK', 'clientIpAddress': '10.xx.x.xxx', 'vserverName': 'svm1', 'suspensionCnt': '4', 'dsId': '1038'}
Wed Jul 26 20:03:02 +0900 [node1: nblade2: Nblade.vscanNoScannerConn:EMERGENCY]: Vserver "svm1" has no virus scanner connection.
Wed Jul 26 20:03:02 +0900 [node1: OffboxVScanTableUpd: Nblade.scannerDisconnected:notice]: Vserver "svm1" disconnected from Vscan server (IP: 10.xx.xx.x).
- Avshim logs show that vscan server is responding but average response time is high:
07/26/23-11:00:35.931Z VS_ScanCompletion: 6170900 requests, avg msec/req 13016
07/26/23-11:00:41.420Z VS_ScanCompletion: 6171000 requests, avg msec/req 13016
07/26/23-11:00:46.708Z VS_ScanCompletion: 6171100 requests, avg msec/req 13016
- TCP session terminated:
07/26/23-11:03:02.942Z [pipe: svm1.domain]Server: Received 32 bytes, ofsPartReq: [0]
07/26/23-11:03:02.942Z[Pipe: svm1.domain]
magic_num : [4e74417041760003]
session_id : [dd76fd900d035587]
len : [32]
reqId : [15243333]
type : [2, req_SESSION_TEARDOWN]
07/26/23-11:03:02.958Z [Pipe: svm1.domain] msg-code : [req_SESSION_TEARDOWN]
07/26/23-11:03:02.958Z [Pipe: svm1.domain] waiting for synchronous-write to finish for msg-code: [req_SESSION_TEARDOWN]
07/26/23-11:03:02.958Z [svm1.domain][Write] GetOverlappedResult failed, err: <38>
07/26/23-11:03:02.958Z Write EOF Error. Closing the pipe: [svm1.domain]0
7/26/23-11:03:02.958Z [Pipe: svm1.domain] wait-sync-write finished with code: [0]
07/26/23-11:03:02.958Z Attempting reverse DNS lookup of 10.x.x.x
07/26/23-11:03:02.958Z Found host svm1.domain for IP 10.x.x.x
07/26/23-11:03:02.958Z 10.x.x.x resolved to svm1.domain
07/26/23-11:03:02.958Z [Pipe: svm1.domain, svm1-01][r] CreateNamedPipe failed with 1. closingQ: [0]
- Later TCP connection between AV server and SVM reestablished but now vscan scanning the file and returning error code "
333300001
":
07/26/23-11:03:02.958Z VS_ScanCompletion: request id 6173274 of path \\?\UNC\svm1.domain\ontap_admin$\share1\file.xls completed with status[333300001, VSENGINE_INTERNAL_ERROR], str 'I'
07/26/23-11:03:02.974Z VS_ScanCompletion: request id 6173288 of path \\?\UNC\svm1.domain\ontap_admin$\share1\file.xls completed with status[333300001, VSENGINE_INTERNAL_ERROR], str 'I'