Setup :
Using vdbench version 50406
From an nfs share, we carve out shares which are provided to Win7 machines as smb share. This smb share is mapped to Z drive. And we run vdbench on this Z drive with journaling enabled.
Here is the configuration file used :
create_anchors=yes
validate=yes
validate=read
validate=read_after_write
validate=no_preread
validate=time
journal=yes
journal=noflush
fsd=fsd1,anchor=z:\vdbench2,depth=1,width=1,files=100,size=(3M,5,1M,5,20M,5,16M,5,8M,5,24M,5,512K,30,128K,20,256K,20)
fwd=fwd1,fsd=fsd1,operation=read,threads=32,fileio=random,xfersize=4k,fileselect=random
fwd=fwd2,fsd=fsd1,operation=write,threads=32,fileio=random,xfersize=4k,fileselect=random
rd=rd1,fwd=fwd*,fwdrate=100,format=yes,elapsed=129600,interval=5,iorate=3
Here is the link to results:
snippet from errorlog.html:
09:37:41.528 localhost-0: 09:37:41.496 Corrupted data block for fsd=fsd1,file=z:\vdbench2\vdb.1_1.dir\vdb_f0082.file; file lba: 0x00001000 xfersize=4096^M
09:37:41.528 localhost-0: 09:37:41.496 ^M
09:37:41.528 localhost-0: 09:37:41.496 Data block has 1 key block(s) of 4096 bytes each.^M
09:37:41.528 localhost-0: 09:37:41.496 All key blocks are corrupted.^M
09:37:41.528 localhost-0: 09:37:41.496 Key block lba: 0x119e1000^M
09:37:41.528 localhost-0: 09:37:41.496 Key block of 4,096 bytes has 8 512-byte sectors.^M
09:37:41.543 localhost-0: 09:37:41.496 Timeline: ^M
09:37:41.543 localhost-0: 09:37:41.512 Sun Aug 27 2017 08:43:33.187 PDT Sector last written. (As found in the first corrupted sector, timestamp is taken just BEFORE the actual write).^M
09:37:41.543 localhost-0: 09:37:41.512 Sun Aug 27 2017 09:21:58.748 PDT Key block was last read_after_write. (Timestamp is taken just AFTER the actual read or write).^M
09:37:41.543 localhost-0: 09:37:41.512 Sun Aug 27 2017 09:37:41.496 PDT Key block first found to be corrupted during a workload requested read.^M
09:37:41.543 localhost-0: 09:37:41.512 ^M
09:37:41.543 localhost-0: 09:37:41.512 All 8 sectors in this key block are corrupted.^M
09:37:41.543 localhost-0: 09:37:41.512 All corruptions are of the same type: ^M
09:37:41.543 localhost-0: 09:37:41.512 ===> Data Validation Key miscompare. Expecting key=0x51 received key=0x50 (81/80)^M
09:37:41.543 localhost-0: 09:37:41.512 Only the FIRST sector will be reported:^M
09:37:41.543 localhost-0: 09:37:41.512 ^M
09:37:41.543 localhost-0: 09:37:41.512 Data Validation error for fsd=fsd1; FSD lba: 0x119e1000; Key block size: 4096; relative sector in data block: 0x00 ^M
09:37:41.543 localhost-0: 09:37:41.512 File name: z:\vdbench2\vdb.1_1.dir\vdb_f0082.file; file block lba: 0x00001000; bad sector file lba: 0x00001000^M
09:37:41.543 localhost-0: 09:37:41.528 0x000 00000000 119e1000 ........ ........ 00000000 119e1000 0000015e 245cc543^M
09:37:41.543 localhost-0: 09:37:41.528 0x010 51..0000 31647366 20202020 00000000 50e70000 31647366 20202020 00000e24^M
09:37:41.543 localhost-0: 09:37:41.528 There are no mismatches in bytes 32-511
^M
09:37:41.543 localhost-0: 09:37:41.543 Time that this key block 0x119e1000 was last used for read_after_write: Sun Aug 27 2017 09:21:58.748 PDT^M
09:37:41.543 localhost-0: 09:37:41.543 09:37:41.543 op: read lun: z:\vdbench2\vdb.1_1.dir\vdb_f0082.file lba: 4096 0x00001000 xfer: 4096 errno: 60003: '60003 A Data Validation error was discovered'
So it wrote 0x51 and expecting 0x51 but got 0x50.
Did it actually write 0x51 ? or it failed and vdbench went ahead for read. ?
We verified the file content again by reading in that offset, it has 0x50 only now.
So did we actually hit data corruption or its false alarm ?