FIO report pattern: verify failed for --verify_pattern=0xff%o\"abcd\"-12

[aepotapov]

fio --verison
fio-3.38

cat /etc/os-release 
PRETTY_NAME="Ubuntu 22.04.5 LTS"
NAME="Ubuntu"
VERSION_ID="22.04"
VERSION="22.04.5 LTS (Jammy Jellyfish)"
VERSION_CODENAME=jammy
ID=ubuntu
ID_LIKE=debian
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
UBUNTU_CODENAME=jammy

uname -a
Linux NB-1828 5.15.145-0515145-generic #202312231032 SMP Sat Dec 23 10:39:58 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

I get verify errors with following two runs:

1. fio --name=pat01-04 --ioengine=libaio --thread --direct=1 --iodepth=4 --rw=write --verify=pattern
--verify_pattern=0xff%o\"abcd\"-12 --do_verify=0 --verify_state_save=0 --end_fsync=1 --group_reporting=1
--directory=./dir01:./dir02 --size=1Gi --blocksize=1Mi --numjobs=2                                                                                          
pat01-04: (g=0): rw=write, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=4                                                                                            
...                                                                                                                                                                                                                
fio-3.38                                                                                                                                                                                                           
Starting 2 threads                                                                                                                                                                                                 
pat01-04: Laying out IO file (1 file / 1024MiB)                                                                                                                                                                    
pat01-04: Laying out IO file (1 file / 1024MiB)                                                                                                                                                                    
Jobs: 2 (f=2)                                                                                                                                                                                                      
pat01-04: (groupid=0, jobs=2): err= 0: pid=40040: Tue Dec  3 17:28:34 2024                                                                                                                                         
  write: IOPS=1935, BW=1936MiB/s (2030MB/s)(2048MiB/1058msec); 0 zone resets                                                                                                                                       
    slat (usec): min=55, max=729, avg=180.58, stdev=91.44                                                                                                                                                          
    clat (usec): min=2181, max=13064, avg=3856.78, stdev=1566.86                                                                                                                                                   
     lat (usec): min=2677, max=13364, avg=4037.37, stdev=1566.46                                                                                                                                                   
    clat percentiles (usec):                                                                                                                                                                                       
     |  1.00th=[ 2900],  5.00th=[ 3195], 10.00th=[ 3294], 20.00th=[ 3359],                                                                                                                                         
     | 30.00th=[ 3425], 40.00th=[ 3458], 50.00th=[ 3490], 60.00th=[ 3523],                                                                                                                                         
     | 70.00th=[ 3556], 80.00th=[ 3589], 90.00th=[ 4228], 95.00th=[ 5014],                                                                                                                                         
     | 99.00th=[12125], 99.50th=[12387], 99.90th=[12780], 99.95th=[12780],                                                                                                                                         
     | 99.99th=[13042]                                                                                                                                                                                             
   bw (  MiB/s): min= 1920, max= 1976, per=100.00%, avg=1948.00, stdev=16.21, samples=4                                                                                                                            
   iops        : min= 1920, max= 1976, avg=1948.00, stdev=16.21, samples=4                                                                                                                                         
  lat (msec)   : 4=85.99%, 10=10.84%, 20=3.17%                                                                                                                                                                     
  cpu          : usr=16.94%, sys=8.94%, ctx=2040, majf=0, minf=2                                                                                                                                                   
  IO depths    : 1=0.1%, 2=0.2%, 4=99.7%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%                                                                                                                                      
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=0,2048,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=4

Run status group 0 (all jobs):
  WRITE: bw=1936MiB/s (2030MB/s), 1936MiB/s-1936MiB/s (2030MB/s-2030MB/s), io=2048MiB (2147MB), run=1058-1058msec

Disk stats (read/write):
  nvme1n1: ios=0/4351, sectors=0/3560464, merge=0/0, ticks=0/16269, in_queue=16272, util=90.05%

3. fio --name=pat01-04 --ioengine=libaio --thread --direct=1 --iodepth=4 --rw=read --verify=pattern
--verify_pattern=0xff%o\"abcd\"-12 --do_verify=1 --verify_only --verify_state_load=0 --verify_dump=1
--group_reporting=1 --directory=./dir01:./dir02 --size=1Gi --blocksize=1Mi --numjobs=2
pat01-04: (g=0): rw=read, bs=(R) 1024KiB-1024KiB, (W) 1024KiB-1024KiB, (T) 1024KiB-1024KiB, ioengine=libaio, iodepth=4
...
fio-3.38
Starting 2 threads
fio: got pattern '30', wanted 'f0'. Bad bits 2
fio: bad pattern block offset 3
pattern: verify failed at file ./dir02/pat01-04.1.0 offset 422576128, length 1048576 (requested block: offset=422576128, length=1048576, flags=8)
       received data dumped as pat01-04.1.0.422576128.received
       expected data dumped as pat01-04.1.0.422576128.expected
fio: verify type mismatch (12288 media, 18 given)
fio: got pattern '50', wanted 'a0'. Bad bits 4
fio: bad pattern block offset 3
pattern: verify failed at file ./dir02/pat01-04.1.0 offset 424673280, length 1048576 (requested block: offset=424673280, length=1048576, flags=8)
       received data dumped as pat01-04.1.0.424673280.received
       expected data dumped as pat01-04.1.0.424673280.expected
fio: verify type mismatch (20480 media, 18 given)
fio: pid=40092, err=84/file:io_u.c:2290, func=io_u_queued_complete, error=Invalid or incomplete multibyte or wide character

pat01-04: (groupid=0, jobs=2): err=84 (file:io_u.c:2290, func=io_u_queued_complete, error=Invalid or incomplete multibyte or wide character): pid=40091: Tue Dec  3 17:28:50 2024
  read: IOPS=2260, BW=2261MiB/s (2370MB/s)(1431MiB/633msec)
    slat (usec): min=34, max=439, avg=92.45, stdev=41.31
    clat (usec): min=766, max=14295, avg=2591.98, stdev=1209.22
     lat (usec): min=891, max=14591, avg=2684.42, stdev=1206.50
    clat percentiles (usec):
     |  1.00th=[ 1090],  5.00th=[ 1287], 10.00th=[ 1401], 20.00th=[ 1500],
     | 30.00th=[ 1598], 40.00th=[ 1876], 50.00th=[ 2966], 60.00th=[ 3130],
     | 70.00th=[ 3261], 80.00th=[ 3425], 90.00th=[ 3621], 95.00th=[ 3785],
     | 99.00th=[ 4228], 99.50th=[10814], 99.90th=[14091], 99.95th=[14353],
     | 99.99th=[14353]
   bw (  MiB/s): min= 1458, max= 1458, per=64.49%, avg=1458.00, stdev= 0.00, samples=1
   iops        : min= 1458, max= 1458, avg=1458.00, stdev= 0.00, samples=1
  lat (usec)   : 1000=0.21%
  lat (msec)   : 2=41.79%, 4=55.90%, 10=1.54%, 20=0.56%
  cpu          : usr=11.98%, sys=17.76%, ctx=1366, majf=0, minf=2563
  IO depths    : 1=0.1%, 2=0.3%, 4=99.6%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
     submit    : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     complete  : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=1431,0,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=4

Run status group 0 (all jobs):
   READ: bw=2261MiB/s (2370MB/s), 2261MiB/s-2261MiB/s (2370MB/s-2370MB/s), io=1431MiB (1501MB), run=633-633msec

Disk stats (read/write):
  nvme1n1: ios=2670/0, sectors=1822720/0, merge=0/0, ticks=8022/0, in_queue=8023, util=80.81%

At the same time comparing dump files says they are the same.

[vincentkfu]

I was able to trigger this issue once but subsequent attempts did not produce verification errors. Do you see this issue every time?

Can you simplify your job file to include only options that are required to produce this issue? https://stackoverflow.com/help/mcve

[aepotapov]

Thank you, I'll try