fio icon indicating copy to clipboard operation
fio copied to clipboard
verified publisher icon axboe

With RT enabled Linux, fio seg-faulted.

Open pangupta opened this issue 6 months ago • 2 comments

CONFIG on LINUX:

CONFIG_DM_CRYPT=y CONFIG_TRUSTED_KEYS=y CONFIG_TRUSTED_KEYS_TEE=y

CONFIG_IMX_SEC_ENCLAVE=n CONFIG_IMX_ELE_TRNG=n

CONFIG_PREEMPT_RT=y CONFIG_BLK_DEV_LOOP=y

Following steps ran on Linux:

a. $:> mkdir -p /data/crypt

b. $:>KEYNAME=dm_trust_plainkey $:>KEY=$(keyctl add trusted $KEYNAME 'new 32' @s) $:>keyctl pipe $KEY > /data/$KEYNAME.blob $:>keyctl list @s

c. $:>DEV=/dev/loop0 $:>ALGO="capi:cbc-aes-tee-plain" $:>dd if=/dev/zero of=/data/crypt/encrypted.img bs=1M count=512 && losetup /dev/loop0 /data/crypt/encrypted.img $:>BLOCKS=$(blockdev --getsz /dev/loop0)

d. $:>TABLE="0 $BLOCKS crypt $ALGO :32:trusted:$KEYNAME 0 $DEV 0 1 sector_size:512" $:>dmsetup -v create encrypted --table "$TABLE"

e. $:>mkfs.ext4 /dev/mapper/encrypted $:>mkdir -p /data/mnt/encrypted $:>mount -t ext4 /dev/mapper/encrypted /data/mnt/encrypted

f. $:>fio --filename=/data/mnt/encrypted/fio.bin --size=128MB --rw=rw --bs=8k --ioengine=sync --iodepth=1 --runtime=120 --numjobs=1 --time_based --group_reporting --name=throughput-test-job --eta-newline=1 root@imx93evk:~#

Below is running commands,

root@imx93evk:~# insmod tee_crypto.ko
root@imx93evk:~# ./dm-crypt-init.sh
root@imx93evk:~# fio --filename=/data/mnt/encrypted/fio.bin --size=16MB --rw=rw --bs=512 --ioengine=sync --iodepth=1 --runtime=120
 --numjobs=1 --time_based --group_reporting --name=throughput-test-job --eta-newline=1
throughput-test-job: (g=0): rw=rw, bs=(R) 512B-512B, (W) 512B-512B, (T) 512B-512B, ioengine=sync, iodepth=1
fio-3.36-117-gb2403
Starting 1 process
Jobs: 1 (f=1): [M(1)][2.5%][r=6675KiB/s,w=6787KiB/s][r=13.4k,w=13.6k IOPS][eta 01m:57s]
Jobs: 1 (f=1): [M(1)][4.1%][r=7617KiB/s,w=7500KiB/s][r=15.2k,w=15.0k IOPS][eta 01m:56s]
Jobs: 1 (f=1): [M(1)][5.8%][r=8540KiB/s,w=8477KiB/s][r=17.1k,w=17.0k IOPS][eta 01m:54s]
Jobs: 1 (f=1): [M(1)][7.4%][r=6339KiB/s,w=6396KiB/s][r=12.7k,w=12.8k IOPS][eta 01m:52s]
Jobs: 1 (f=1): [M(1)][9.1%][r=6710KiB/s,w=6790KiB/s][r=13.4k,w=13.6k IOPS][eta 01m:50s]
Jobs: 1 (f=1): [M(1)][9.9%][r=24.2MiB/s,w=24.3MiB/s][r=49.6k,w=49.8k IOPS][eta 01m:49s]
Jobs: 1 (f=1): [M(1)][10.7%][r=19.9MiB/s,w=19.9MiB/s][r=40.8k,w=40.8k IOPS][eta 01m:48s]
Jobs: 1 (f=1): [M(1)][12.4%][r=6286KiB/s,w=6202KiB/s][r=12.6k,w=12.4k IOPS][eta 01m:46s]
Jobs: 1 (f=1): [M(1)][13.2%][r=6531KiB/s,w=6511KiB/s][r=13.1k,w=13.0k IOPS][eta 01m:45s]
Jobs: 1 (f=1): [M(1)][14.9%][r=7685KiB/s,w=7813KiB/s][r=15.4k,w=15.6k IOPS][eta 01m:43s]
Jobs: 1 (f=1): [M(1)][16.5%][r=7179KiB/s,w=7212KiB/s][r=14.4k,w=14.4k IOPS][eta 01m:41s]
Jobs: 1 (f=1): [M(1)][17.4%][r=6685KiB/s,w=6616KiB/s][r=13.4k,w=13.2k IOPS][eta 01m:40s]
Jobs: 1 (f=1): [M(1)][19.0%][r=9592KiB/s,w=9614KiB/s][r=19.2k,w=19.2k IOPS][eta 01m:38s]
Segmentation fault (core dumped)947KiB/s,w=9007KiB/s][r=17.9k,w=18.0k IOPS][eta 01m:36s]
root@imx93evk:~#

(gdb) run --filename=/data/mnt/encrypted/fio.bin --size=128MB --rw=rw --bs=8k --ioengine=sync --iodepth=1 --runtime=120 --numjobs=1 --time_based --group_reporting --name=throughput-test-job --eta-newline=1
(gdb) bt
#0  __memchr_generic () at ../sysdeps/aarch64/multiarch/../memchr.S:64
#1  0x0000fffff7d2cd38 in __GI__IO_getline_info (fp=fp@entry=0xffffe8000b70,
    buf=buf@entry=0xffffeed92418 "\214\203\255\252\252\252", n=n@entry=255, delim=delim@entry=10,
    extract_delim=extract_delim@entry=1, eof=eof@entry=0x0) at iogetline.c:85
#2  0x0000fffff7d2ce5c in __GI__IO_getline (fp=fp@entry=0xffffe8000b70, buf=buf@entry=0xffffeed92418 "\214\203\255\252\252\252",
    n=n@entry=255, delim=delim@entry=10, extract_delim=extract_delim@entry=1) at iogetline.c:34
#3  0x0000fffff7d2b898 in _IO_fgets (buf=buf@entry=0xffffeed92418 "\214\203\255\252\252\252", n=n@entry=256,
    fp=fp@entry=0xffffe8000b70) at iofgets.c:53
#4  0x0000aaaaaab1b200 in fgets (__stream=0xffffe8000b70, __n=256, __s=0xffffeed92418 "\214\203\255\252\252\252")
    at /usr/include/bits/stdio2.h:200
#5  get_io_ticks (du=du@entry=0xfffff6ca5570, dus=dus@entry=0xffffeed92570) at diskutil.c:59
#6  0x0000aaaaaab1beec in update_io_tick_disk (du=0xfffff6ca5570) at diskutil.c:104
#7  update_io_ticks () at diskutil.c:141
#8  0x0000aaaaaab0d7c8 in eval_timer (msec_to_next_event=<synthetic pointer>, now=0xffffeed926c0, it=0xffffeed926f0)
    at helper_thread.c:270
#9  helper_thread_main (data=0xfffff6ca54f0) at helper_thread.c:338
#10 0x0000fffff7d40fc4 in start_thread (arg=0x0) at pthread_create.c:447
#11 0x0000fffff7da31cc in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone3.S:76
(gdb) l
59      in ../sysdeps/aarch64/multiarch/../memchr.S

Other observations:

  1. Issue is not coming with CONFIG_PREEMPT_RT=n
  2. FIO repo used: https://git.kernel.dk/cgit/fio/
  3. FIO branch (commit): master (7037b833e175aae32900b73bf597aad08c1d8472)
  4. When compile fio with CFLAG+= +g, crash is coming at file:io_u.c:2274.

Please suggest your views. Thanks.

pangupta avatar Jul 11 '25 08:07 pangupta

Hello @pangupta :

What happens when you set disk_util=0 ?

sitsofe avatar Jul 11 '25 13:07 sitsofe

with --disk_util=0, same crash is seen. crash logs:

root@imx93evk:~# ./fio_g --filename=/data/mnt/encrypted/fio.bin --size=128MB --rw=rw --bs=8k --ioengine=sync --iodepth=1 --runtime=120 --numjobs=1 --time_based --group_reporting --name=throughput-test-job --eta-newline=1 --disk_util=0
throughput-test-job: (g=0): rw=rw, bs=(R) 8192B-8192B, (W) 8192B-8192B, (T) 8192B-8192B, ioengine=sync, iodepth=1
fio-3.40-11-g7037b
Starting 1 process
fio: pid=721, err=1769919122/file:io_u.c:2263, func=io_u_sync_complete, error=Unknown error 1769919122

throughput-test-job: (groupid=0, jobs=1): err=1769919122 (file:io_u.c:2263, func=io_u_sync_complete, error=Unknown error 1769919122): pid=721: Mon Jun  2 16:36:56 2025
  read: IOPS=22.4k, BW=175MiB/s (184MB/s)(438MiB/2497msec)
    clat (usec): min=3, max=8552, avg=-188646951575563109602492639412672121360554377831674148963446915326626173991506918026046307786096763194459310784675040648952268477737156610050194216471356041143296315188691599360.00, stdev=  inf
     lat (usec): min=3, max=8553, avg=13.64, stdev=156.22
    clat percentiles (usec):
     |  1.00th=[    5],  5.00th=[    5], 10.00th=[    5], 20.00th=[    5],
     | 30.00th=[    5], 40.00th=[    6], 50.00th=[    6], 60.00th=[    6],
     | 70.00th=[    6], 80.00th=[    6], 90.00th=[    7], 95.00th=[   13],
     | 99.00th=[   36], 99.50th=[  188], 99.90th=[ 2704], 99.95th=[ 4113],
     | 99.99th=[ 6063]
   bw (  KiB/s): min=32944, max=373488, per=99.77%, avg=179013.80, stdev=132888.43, samples=5
   iops        : min= 4118, max=46686, avg=22376.60, stdev=16611.02, samples=5
  write: IOPS=22.5k, BW=176MiB/s (185MB/s)(440MiB/2497msec); 0 zone resets
    clat (nsec): min=5042, max=30053k, avg=469.42, stdev=  nan
     lat (usec): min=5, max=30053, avg=13.02, stdev=455.10
    clat percentiles (usec):
     |  1.00th=[    6],  5.00th=[    6], 10.00th=[    6], 20.00th=[    7],
     | 30.00th=[    7], 40.00th=[    8], 50.00th=[    9], 60.00th=[    9],
     | 70.00th=[   12], 80.00th=[   15], 90.00th=[   19], 95.00th=[   24],
     | 99.00th=[   61], 99.50th=[   84], 99.90th=[ 1598], 99.95th=[ 2073],
     | 99.99th=[25822]
   bw (  KiB/s): min=32000, max=377872, per=99.77%, avg=179861.60, stdev=135048.02, samples=5
   iops        : min= 4000, max=47234, avg=22482.60, stdev=16881.04, samples=5
  lat (usec)   : 4=0.25%, 10=81.04%, 20=14.17%, 50=3.54%, 100=0.51%
  lat (usec)   : 250=0.18%, 500=0.11%,t�;)���jò�-L�Y[��<s\
                                                          �D�Ņ�ec)   : 2=0.01%, 4=0.01%, 10=0.01%, 20=0.01%, 50=0.01%
  cpu          : usr=12.74%, sys=45.95%, ctx=2104, majf=0, minf=29
  IO depths    : 1=100.0%, 2=0.0%, 4=0.0%, 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.1%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=56003,56268,0,0 short=0,0,0,0 dropped=0,0,0,0
     latency   : target=0, window=0, percentile=100.00%, depth=1

Run status group 0 (all jobs):
   READ: bw=175MiB/s (184MB/s), 175MiB/s-175MiB/s (184MB/s-184MB/s), io=438MiB (459MB), run=2497-2497msec
  WRITE: bw=176MiB/s (185MB/s), 176MiB/s-176MiB/s (185MB/s-185MB/s), io=440MiB (461MB), run=2497-2497msec

pangupta avatar Jul 15 '25 10:07 pangupta