Errors 823/824 - SQL Server detected a logical consistency-based I/O error when VM is running on snapshot
search cancel

Errors 823/824 - SQL Server detected a logical consistency-based I/O error when VM is running on snapshot

book

Article ID: 317915

calendar_today

Updated On:

Products

VMware vSphere ESXi

Issue/Introduction

Symptoms:
  • 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

 

  • vmware.log shows

2022-03-01T20:43:52.549Z| vmx| | I005: SnapshotVMX_TakeSnapshot start: 'VEEAM BACKUP TEMPORARY SNAPSHOT', deviceState=0, lazy=0, quiesced=0, forceNative=0, tryNative=1, saveAllocMaps=0
2022-03-01T20:43:55.676Z| vcpu-0| | I005: HBACommon: First write on scsi3:0.fileName='/vmfs/volumes/61791a84-06f88fca-2653-e43d1a2c7d20/vmname/vmname-000002.vmdk'
2022-03-01T20:43:55.676Z| vcpu-0| | I005: DDB: "longContentID" = "a224b7d96b238399216eeb33c3e01a7a" (was "f943a40bcc86c18a1ba59d1c3e63e024")
2022-03-01T20:43:55.686Z| vcpu-0| | I005: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x3e63e024, new=0xc3e01a7a (a224b7d96b238399216eeb33c3e01a7a)
2022-03-01T20:44:03.646Z| vcpu-0| | A000: <<< file Throttled >>>
2022-03-01T20:44:03.646Z| vcpu-0| | I005: HBACommon: First write on scsi3:1.fileName='/vmfs/volumes/617aaa3c-11977464-688e-e43d1a2c7d20/vmname/vmname_1-000001.vmdk'
2022-03-01T20:44:03.647Z| vcpu-0| | I005: DDB: "longContentID" = "e08eea36ebfc3edc68f2174adfef8c86" (was "e961c662885d85b5f558067e6968c37b")
2022-03-01T20:44:03.658Z| vcpu-0| | I005: DISKLIB-CHAIN : DiskChainUpdateContentID: old=0x6968c37b, new=0xdfef8c86 (e08eea36ebfc3edc68f2174adfef8c86)
2022-03-01T21:12:41.961Z| vmx| | I005: VigorTransportProcessClientPayload: opID=480e454f-5d-6c2c seq=2695258: Receiving GuestOps.DeleteFile request.
2022-03-01T21:12:42.768Z| vcpu-8| | I005: VigorTransport_ServerSendResponse opID=480e454f-5d-6c2c seq=2695258: Completed GuestOps request.
2022-03-01T21:45:16.210Z| vmx| | I005: VigorTransportProcessClientPayload: opID=28372fdd-6d-8082 seq=2696792: Receiving Snapshot.Delete request

 

  • vmkernel.log shows

2022-03-01T20:43:53.375Z cpu13:2103234 opID=2086d542)CBT: 1346: Created device 1375224b-cbt for cbt driver with filehandle 326443595
2022-03-01T20:43:53.375Z cpu13:2103234 opID=2086d542)VSCSI: 4231: handle 12738(vscsi3:1):Creating Virtual Device for world 2103001 (FSS handle 301343309) numBlocks=419430400 (bs=512)
2022-03-01T20:43:53.375Z cpu13:2103234 opID=2086d542)VSCSI: 273: handle 12738(vscsi3:1):Input values: res=0 limit=-2 bw=-1 Shares=1000
2022-03-01T20:43:53.375Z cpu13:2103234 opID=2086d542)Vmxnet3: 13979: indLROPktToGuest: 1, vcd->umkShared->vrrsSelected: 7 port 0x4000025

2022-03-01T20:43:53.375Z cpu13:2103234 opID=2086d542)Vmxnet3: 14246: Using default queue delivery for vmxnet3 for port 0x4000025
2022-03-01T21:01:02.519Z cpu24:2097306)------------ ------------ ------------ ------------ ------------ ------------------------------

2022-03-01T21:01:02.519Z cpu24:2097306) min,KB max,KB minLimit,KB eMin,KB rMinPeak,KB name

 

  • vobd.log shows

2022-03-01T20:35:41.032Z: [vmfsCorrelator] 3477497752498us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
2022-03-01T20:35:41.032Z: [vmfsCorrelator] 3477542166589us: [esx.audit.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
2022-03-01T21:40:19.514Z: [vmfsCorrelator] 3481376185290us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Bloom Filter full
2022-03-01T21:40:19.515Z: [vmfsCorrelator] 3481420649402us: [esx.audit.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Bloom Filter full
2022-03-01T21:45:16.480Z: [vmfsCorrelator] 3481673146918us: [vob.vmfs.sesparse.bloomfilter.disabled] Read IO performance maybe impacted for disk vmname-flat.vmdk: Non-empty delta disk being opened
2022-03-01T21:45:16.480Z: [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

Cause

Root cause is under investigation.

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 again for the changes to take affect.


NOTE: In VMware vSphere ESXi 7.0 U3f/8.0 the bloom filter is disabled.


Additional Information

Impact/Risks:
Requires power off and power on of 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