gocryptfs icon indicating copy to clipboard operation
gocryptfs copied to clipboard

ExFAT: `SEEK_DATA` and `SEEK_HOLE`

Open savchenko opened this issue 1 year ago • 0 comments

While investigating slow speed of the mounted exFAT share, I have noticed that -fsck returns this to the stdout:

unsupported block size of 131072 bytes, disabling SEEK_DATA & SEEK_HOLE

Software stack

Gocryptfs 2.3; go-fuse 2.1.0+git20220822.58a7e14; 2023-04-09 go1.19.8 linux/amd64
Kernel 6.1.0-3-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.1.8-1 (2023-01-29)
Fuse 3.14.0-4

Write speeds

Raw exFAT mount

dd
dd if=/dev/zero of=raw_exfat_mount.img bs=1G count=1 conv=fdatasync
1073741824 bytes (1.1 GB, 1.0 GiB) copied, 3 s, 360 MB/s
fio
fio --name TEST --eta-newline=5s --filename=raw_exfat.dat --rw=randrw --size=500m --io_size=10g --blocksize=4k --ioengine=libaio --fsync=1 --iodepth=1 --direct=1 --numjobs=1 --runtime=60 --group_reporting
TEST: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.33
Starting 1 process
TEST: Laying out IO file (1 file / 500MiB)
Jobs: 1 (f=1): [m(1)][13.1%][r=3388KiB/s,w=3364KiB/s][r=847,w=841 IOPS][eta 00m:53s]
Jobs: 1 (f=1): [m(1)][23.0%][r=3575KiB/s,w=3427KiB/s][r=893,w=856 IOPS][eta 00m:47s] 
Jobs: 1 (f=1): [m(1)][32.8%][r=3523KiB/s,w=3371KiB/s][r=880,w=842 IOPS][eta 00m:41s] 
Jobs: 1 (f=1): [m(1)][42.6%][r=3480KiB/s,w=3364KiB/s][r=870,w=841 IOPS][eta 00m:35s] 
Jobs: 1 (f=1): [m(1)][52.5%][r=3223KiB/s,w=3367KiB/s][r=805,w=841 IOPS][eta 00m:29s] 
Jobs: 1 (f=1): [m(1)][62.3%][r=3568KiB/s,w=3412KiB/s][r=892,w=853 IOPS][eta 00m:23s] 
Jobs: 1 (f=1): [m(1)][72.1%][r=3215KiB/s,w=3383KiB/s][r=803,w=845 IOPS][eta 00m:17s] 
Jobs: 1 (f=1): [m(1)][82.0%][r=3707KiB/s,w=3375KiB/s][r=926,w=843 IOPS][eta 00m:11s] 
Jobs: 1 (f=1): [m(1)][91.8%][r=3536KiB/s,w=3412KiB/s][r=884,w=853 IOPS][eta 00m:05s] 
Jobs: 1 (f=1): [m(1)][100.0%][r=2968KiB/s,w=3388KiB/s][r=742,w=847 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=26044: Thu Jun  8 10:49:07 2023
  read: IOPS=850, BW=3402KiB/s (3484kB/s)(199MiB/60001msec)
    slat (nsec): min=2640, max=24061, avg=3798.85, stdev=1035.87
    clat (usec): min=69, max=3533, avg=83.59, stdev=17.59
     lat (usec): min=73, max=3557, avg=87.39, stdev=17.76
    clat percentiles (usec):
     |  1.00th=[   73],  5.00th=[   74], 10.00th=[   74], 20.00th=[   75],
     | 30.00th=[   76], 40.00th=[   77], 50.00th=[   87], 60.00th=[   91],
     | 70.00th=[   92], 80.00th=[   93], 90.00th=[   93], 95.00th=[   94],
     | 99.00th=[   96], 99.50th=[   97], 99.90th=[  111], 99.95th=[  116],
     | 99.99th=[  133]
   bw (  KiB/s): min= 2960, max= 4072, per=100.00%, avg=3406.32, stdev=218.00, samples=119
   iops        : min=  740, max= 1018, avg=851.58, stdev=54.50, samples=119
  write: IOPS=847, BW=3389KiB/s (3470kB/s)(199MiB/60001msec); 0 zone resets
    slat (usec): min=2, max=158, avg= 3.93, stdev= 1.25
    clat (usec): min=29, max=242, avg=33.98, stdev= 2.06
     lat (usec): min=33, max=245, avg=37.91, stdev= 2.77
    clat percentiles (nsec):
     |  1.00th=[30848],  5.00th=[30848], 10.00th=[31360], 20.00th=[31872],
     | 30.00th=[33024], 40.00th=[34048], 50.00th=[34048], 60.00th=[34560],
     | 70.00th=[35072], 80.00th=[35584], 90.00th=[36096], 95.00th=[36608],
     | 99.00th=[37632], 99.50th=[38656], 99.90th=[44288], 99.95th=[47872],
     | 99.99th=[53504]
   bw (  KiB/s): min= 3176, max= 3536, per=100.00%, avg=3389.98, stdev=80.27, samples=119
   iops        : min=  794, max=  884, avg=847.50, stdev=20.07, samples=119
  lat (usec)   : 50=49.89%, 100=49.99%, 250=0.12%
  lat (msec)   : 4=0.01%
  fsync/fdatasync/sync_file_range:
    sync (usec): min=109, max=7353, avg=584.67, stdev=456.89
    sync percentiles (usec):
     |  1.00th=[  113],  5.00th=[  116], 10.00th=[  117], 20.00th=[  123],
     | 30.00th=[  133], 40.00th=[  139], 50.00th=[  873], 60.00th=[  889],
     | 70.00th=[  898], 80.00th=[  963], 90.00th=[  988], 95.00th=[ 1029],
     | 99.00th=[ 1336], 99.50th=[ 1434], 99.90th=[ 5080], 99.95th=[ 5145],
     | 99.99th=[ 5211]
  cpu          : usr=0.35%, sys=1.71%, ctx=329499, majf=0, minf=13
  IO depths    : 1=200.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.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=51033,50829,0,101859 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=3402KiB/s (3484kB/s), 3402KiB/s-3402KiB/s (3484kB/s-3484kB/s), io=199MiB (209MB), run=60001-60001msec
  WRITE: bw=3389KiB/s (3470kB/s), 3389KiB/s-3389KiB/s (3470kB/s-3470kB/s), io=199MiB (208MB), run=60001-60001msec

Disk stats (read/write):
  sda: ios=50937/164355, merge=0/0, ticks=4238/54598, in_queue=111438, util=99.88%

GoCryptFS

dd

Fails for some reason, even with sudo

dd if=/dev/zero of=crypt.img bs=1G count=1
dd: failed to open 'crypt.img': Permission denied
fio
fio --name TEST --eta-newline=5s --filename=crypt.dat --rw=randrw --size=500m --io_size=10g --blocksize=4k --ioengine=libaio --fsync=1 --iodepth=1 -
-direct=1 --numjobs=1 --runtime=60 --group_reporting
TEST: (g=0): rw=randrw, bs=(R) 4096B-4096B, (W) 4096B-4096B, (T) 4096B-4096B, ioengine=libaio, iodepth=1
fio-3.33
Starting 1 process
TEST: Laying out IO file (1 file / 500MiB)
Jobs: 1 (f=1): [m(1)][13.1%][r=3380KiB/s,w=3084KiB/s][r=845,w=771 IOPS][eta 00m:53s]
Jobs: 1 (f=1): [m(1)][23.0%][r=3255KiB/s,w=3147KiB/s][r=813,w=786 IOPS][eta 00m:47s] 
Jobs: 1 (f=1): [m(1)][32.8%][r=3364KiB/s,w=3100KiB/s][r=841,w=775 IOPS][eta 00m:41s] 
Jobs: 1 (f=1): [m(1)][42.6%][r=3016KiB/s,w=3068KiB/s][r=754,w=767 IOPS][eta 00m:35s] 
Jobs: 1 (f=1): [m(1)][52.5%][r=2844KiB/s,w=3076KiB/s][r=711,w=769 IOPS][eta 00m:29s] 
Jobs: 1 (f=1): [m(1)][62.3%][r=3036KiB/s,w=3168KiB/s][r=759,w=792 IOPS][eta 00m:23s] 
Jobs: 1 (f=1): [m(1)][72.1%][r=2964KiB/s,w=3044KiB/s][r=741,w=761 IOPS][eta 00m:17s] 
Jobs: 1 (f=1): [m(1)][82.0%][r=3320KiB/s,w=3188KiB/s][r=830,w=797 IOPS][eta 00m:11s] 
Jobs: 1 (f=1): [m(1)][91.8%][r=3363KiB/s,w=3179KiB/s][r=840,w=794 IOPS][eta 00m:05s] 
Jobs: 1 (f=1): [m(1)][100.0%][r=3336KiB/s,w=3172KiB/s][r=834,w=793 IOPS][eta 00m:00s]
TEST: (groupid=0, jobs=1): err= 0: pid=26356: Thu Jun  8 10:51:30 2023
  read: IOPS=786, BW=3147KiB/s (3223kB/s)(184MiB/60001msec)
    slat (usec): min=8, max=501, avg=22.40, stdev= 8.92
    clat (nsec): min=380, max=9150, avg=787.44, stdev=201.55
     lat (usec): min=8, max=502, avg=23.18, stdev= 8.99
    clat percentiles (nsec):
     |  1.00th=[  402],  5.00th=[  422], 10.00th=[  524], 20.00th=[  684],
     | 30.00th=[  780], 40.00th=[  788], 50.00th=[  804], 60.00th=[  820],
     | 70.00th=[  844], 80.00th=[  868], 90.00th=[  948], 95.00th=[ 1012],
     | 99.00th=[ 1288], 99.50th=[ 1528], 99.90th=[ 2064], 99.95th=[ 2416],
     | 99.99th=[ 6112]
   bw (  KiB/s): min= 2624, max= 3696, per=99.93%, avg=3145.61, stdev=233.51, samples=119
   iops        : min=  656, max=  924, avg=786.40, stdev=58.38, samples=119
  write: IOPS=781, BW=3126KiB/s (3201kB/s)(183MiB/60001msec); 0 zone resets
    slat (usec): min=15, max=462, avg=29.47, stdev= 7.59
    clat (nsec): min=390, max=42520, avg=809.33, stdev=330.99
     lat (usec): min=16, max=464, avg=30.28, stdev= 7.66
    clat percentiles (nsec):
     |  1.00th=[  410],  5.00th=[  442], 10.00th=[  532], 20.00th=[  724],
     | 30.00th=[  804], 40.00th=[  812], 50.00th=[  820], 60.00th=[  828],
     | 70.00th=[  852], 80.00th=[  892], 90.00th=[  964], 95.00th=[ 1048],
     | 99.00th=[ 1352], 99.50th=[ 1576], 99.90th=[ 2128], 99.95th=[ 2640],
     | 99.99th=[ 8640]
   bw (  KiB/s): min= 2832, max= 3328, per=99.96%, avg=3125.24, stdev=99.92, samples=119
   iops        : min=  708, max=  832, avg=781.31, stdev=24.98, samples=119
  lat (nsec)   : 500=8.09%, 750=14.66%, 1000=70.89%
  lat (usec)   : 2=6.23%, 4=0.10%, 10=0.03%, 20=0.01%, 50=0.01%
  fsync/fdatasync/sync_file_range:
    sync (usec): min=46, max=7385, avg=611.04, stdev=532.56
    sync percentiles (usec):
     |  1.00th=[   52],  5.00th=[   54], 10.00th=[   56], 20.00th=[   58],
     | 30.00th=[   61], 40.00th=[   68], 50.00th=[  947], 60.00th=[  971],
     | 70.00th=[  996], 80.00th=[ 1020], 90.00th=[ 1057], 95.00th=[ 1303],
     | 99.00th=[ 1401], 99.50th=[ 1516], 99.90th=[ 5080], 99.95th=[ 5145],
     | 99.99th=[ 5276]
  cpu          : usr=0.57%, sys=1.54%, ctx=258524, majf=0, minf=13
  IO depths    : 1=200.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.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
     issued rwts: total=47210,46893,0,94100 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=3147KiB/s (3223kB/s), 3147KiB/s-3147KiB/s (3223kB/s-3223kB/s), io=184MiB (193MB), run=60001-60001msec
  WRITE: bw=3126KiB/s (3201kB/s), 3126KiB/s-3126KiB/s (3201kB/s-3201kB/s), io=183MiB (192MB), run=60001-60001msec

savchenko avatar Jun 08 '23 01:06 savchenko