When VM is running on snapshot, we get 823/824 - SQL Server detected a logical consistency-based I/O error
search cancel

When VM is running on snapshot, we get 823/824 - SQL Server detected a logical consistency-based I/O error

book

Article ID: 317915

calendar_today

Updated On:

Products

VMware vSphere ESXi

Issue/Introduction


  • Windows server running MSSQL  and  tempDB running on snapshot/while taking snapshot, event logs report error 823/824
  • Event description of SQL server event logs states

DESCRIPTION: SQL Server detected a logical consistency-based I/O error: incorrect checksum (expected: 0x713e0d75; actual: 0x5f1e6db3). It occurred during a read of page (5:528336) in database ID 2 at offset 0x00000101fa0000 in file 'T:\MSSQL15.MSSQLSERVER\MSSQL\Data\tempdb_mssql_4.ndf'. Additional messages in the SQL Server error log or operating system error log may provide more detail. This is a severe error condition that threatens database integrity and must be corrected immediately. Complete a full database consistency check (DBCC CHECKDB). This error can be caused by many factors; for more information, see SQL Server Books Online

  • VM - /vmfs/volumes/<datastore_name_or_id>/<vm_name>/vmware.log shows the errors below:

[YYYY-MM-DDTHH:MM:SS]| vmx| | I005: SnapshotVMX_TakeSnapshot start: 'VEEAM BACKUP TEMPORARY SNAPSHOT', deviceState=0, lazy=0, quiesced=0, forceNative=0, tryNative=1, saveAllocMaps=0
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: HBACommon: First write on scsi3:0.fileName='/vmfs/volumes/<datastore_id>/vmname/vmname-000002.vmdk'
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: DDB: "longContentID" = "a224b7d96b238399216eeb33c3e01a7a" (was "f943a40bcc86c18a1ba59d1c3e63e024")
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x3e63e024, new=0xc3e01a7a (a224b7d96b238399216eeb33c3e01a7a)
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | A000: <<< file Throttled >>>
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: HBACommon: First write on scsi3:1.fileName='/vmfs/volumes/<datastore_id>/vmname/vmname_1-000001.vmdk'
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: DDB: "longContentID" = "e08eea36ebfc3edc68f2174adfef8c86" (was "e961c662885d85b5f558067e6968c37b")
[YYYY-MM-DDTHH:MM:SS]| vcpu-0| | I005: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x6968c37b, new=0xdfef8c86 (e08eea36ebfc3edc68f2174adfef8c86)
[YYYY-MM-DDTHH:MM:SS]| vmx| | I005: VigorTransportProcessClientPayload: opID=<ID> seq=2695258: Receiving GuestOps.DeleteFile request.
[YYYY-MM-DDTHH:MM:SS]| vcpu-8| | I005: VigorTransport_ServerSendResponse opID=<ID> seq=2695258: Completed GuestOps request.
[YYYY-MM-DDTHH:MM:SS]| vmx| | I005: VigorTransportProcessClientPayload: opID=<ID> seq=2696792: Receiving Snapshot.Delete request

  • ESXi - /var/run/log/vmkernel.log shows the errors below:

[YYYY-MM-DDTHH:MM:SS] cpu13:2103234 opID=<ID> CBT: 1346: Created device 1375224b-cbt for cbt driver with filehandle 326443595
[YYYY-MM-DDTHH:MM:SS] cpu13:2103234 opID=<ID>VSCSI: 4231: handle 12738(vscsi3:1):Creating Virtual Device for world 2103001 (FSS handle 301343309) numBlocks=419430400 (bs=512)
[YYYY-MM-DDTHH:MM:SS] cpu13:2103234 opID=<ID> VSCSI: 273: handle 12738(vscsi3:1):Input values: res=0 limit=-2 bw=-1 Shares=1000
[YYYY-MM-DDTHH:MM:SS] cpu13:2103234 opID=<ID> Vmxnet3: 13979: indLROPktToGuest: 1, vcd->umkShared->vrrsSelected: 7 port 0x4000025
[YYYY-MM-DDTHH:MM:SS]
[YYYY-MM-DDTHH:MM:SS] cpu13:2103234 opID=2086d542)Vmxnet3: 14246: Using default queue delivery for vmxnet3 for port 0x4000025
[YYYY-MM-DDTHH:MM:SS] cpu24:2097306)------------ ------------ ------------ ------------ ------------ ------------------------------
[YYYY-MM-DDTHH:MM:SS]
[YYYY-MM-DDTHH:MM:SS] cpu24:2097306) min,KB max,KB minLimit,KB eMin,KB rMinPeak,KB name

  • ESXi - /var/run/log/vobd.log shows the errors below:

[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3477497752498us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3477542166589us: [esx.audit.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3481376185290us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Bloom Filter full
[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3481420649402us: [esx.audit.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Bloom Filter full
[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3481673146918us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
[YYYY-MM-DDTHH:MM:SS]: [vmfsCorrelator] 3481717614779us: [esx.audit.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened

Note: The preceding log excerpts are only examples. Date, time and environmental variables may vary depending on your environment.

Environment

VMware vSphere ESXi 7.0.x

Resolution

Currently, there is no resolution.

Workaround:

To workaround this issue without powering off the VM

  1. Disable the bloom filter on the ESXi host running the SQL VM by setting the config option.
    esxcli system settings advanced set -i 0 -o /SE/BFEnabled

  2. vMotion the VM to another ESXi host and back to the original ESXi host for the changes to take effect.


NOTE: In VMware vSphere ESXi 7.0 U3f and 8.0, the bloom filter is disabled by default. The workaround does not need to be performed manually.

Please check the ESXi 7.0 U3f release notes below:

VMware ESXi 7.0 Update 3f Release Notes

Additional Information

Impact/Risks:
Requires a power off and power on of the VM. Bloom filter was introduced to boost read IO performance in SESparse. When bloom filter is turned off, read I/O performance will be in-line with ESXi 6.7 release.
Powered by Wolken Software