sync write is very poor

fisherwei

Dabbler
Joined
Oct 28, 2013
Messages
47
i knew sync write will slower than async, if it doesn't have slog device, but in my case, it is very very slow.

cpu: e5-2630 6c 2.4g, disabled HT
mem: 256g ddr3
pool: 8x 7200rpm sata HDD @ raidz2

fio test result:
sync=disabled:
# fio --directory=/mnt/pool0/async -direct=1 -iodepth 32 -thread -rw=write -ioengine=psync -bs=16k -size=20G -numjobs=6 -runtime=60 -group_reporting -name=mytest mytest: (g=0): rw=write, bs=(R) 16.0KiB-16.0KiB, (W) 16.0KiB-16.0KiB, (T) 16.0KiB-16.0KiB, ioengine=psync, iodepth=32 ... fio-3.19 Starting 6 threads Jobs: 6 (f=6): [W(6)][100.0%][w=1059MiB/s][w=67.8k IOPS][eta 00m:00s] mytest: (groupid=0, jobs=6): err= 0: pid=102015: Tue Feb 9 17:18:00 2021 write: IOPS=48.7k, BW=760MiB/s (797MB/s)(44.6GiB/60001msec) clat (usec): min=15, max=1246.3k, avg=117.03, stdev=2114.54 lat (usec): min=16, max=1246.3k, avg=118.04, stdev=2117.79 clat percentiles (usec): | 1.00th=[ 18], 5.00th=[ 19], 10.00th=[ 19], 20.00th=[ 20], | 30.00th=[ 20], 40.00th=[ 20], 50.00th=[ 21], 60.00th=[ 22], | 70.00th=[ 30], 80.00th=[ 76], 90.00th=[ 147], 95.00th=[ 235], | 99.00th=[ 1172], 99.50th=[ 1647], 99.90th=[ 8586], 99.95th=[15926], | 99.99th=[57410] bw ( KiB/s): min=41130, max=2701435, per=100.00%, avg=781261.51, stdev=81059.81, samples=699 iops : min= 2570, max=168837, avg=48826.03, stdev=5066.20, samples=699 lat (usec) : 20=45.60%, 50=26.36%, 100=13.09%, 250=10.33%, 500=1.50% lat (usec) : 750=0.30%, 1000=0.17% lat (msec) : 2=2.24%, 4=0.20%, 10=0.13%, 20=0.05%, 50=0.03% lat (msec) : 100=0.01%, 250=0.01%, 500=0.01%, 750=0.01%, 1000=0.01% lat (msec) : 2000=0.01% cpu : usr=3.19%, sys=23.63%, ctx=913150, majf=0, minf=0 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.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=0,2920145,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=32 Run status group 0 (all jobs): WRITE: bw=760MiB/s (797MB/s), 760MiB/s-760MiB/s (797MB/s-797MB/s), io=44.6GiB (47.8GB), run=60001-60001msec

sync=always:
# fio --directory=/mnt/pool0/sync -direct=1 -iodepth 32 -thread -rw=write -ioengine=psync -bs=16k -size=20G -numjobs=6 -runtime=60 -group_reporting -name=mytest mytest: (g=0): rw=write, bs=(R) 16.0KiB-16.0KiB, (W) 16.0KiB-16.0KiB, (T) 16.0KiB-16.0KiB, ioengine=psync, iodepth=32 ... fio-3.19 Starting 6 threads Jobs: 6 (f=6): [W(6)][100.0%][w=1219KiB/s][w=76 IOPS][eta 00m:00s] mytest: (groupid=0, jobs=6): err= 0: pid=102024: Tue Feb 9 17:19:52 2021 write: IOPS=106, BW=1697KiB/s (1737kB/s)(99.6MiB/60092msec) clat (usec): min=1215, max=188595, avg=56569.53, stdev=40079.17 lat (usec): min=1217, max=188599, avg=56572.45, stdev=40079.54 clat percentiles (msec): | 1.00th=[ 9], 5.00th=[ 17], 10.00th=[ 17], 20.00th=[ 21], | 30.00th=[ 26], 40.00th=[ 34], 50.00th=[ 43], 60.00th=[ 55], | 70.00th=[ 73], 80.00th=[ 97], 90.00th=[ 120], 95.00th=[ 134], | 99.00th=[ 161], 99.50th=[ 178], 99.90th=[ 188], 99.95th=[ 188], | 99.99th=[ 188] bw ( KiB/s): min= 732, max= 4722, per=100.00%, avg=1697.90, stdev=113.22, samples=702 iops : min= 42, max= 294, avg=102.26, stdev= 7.12, samples=702 lat (msec) : 2=0.28%, 4=0.09%, 10=1.04%, 20=17.15%, 50=37.15% lat (msec) : 100=26.30%, 250=17.98% cpu : usr=0.03%, sys=0.24%, ctx=13496, majf=0, minf=0 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.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued rwts: total=0,6372,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=32 Run status group 0 (all jobs): WRITE: bw=1697KiB/s (1737kB/s), 1697KiB/s-1697KiB/s (1737kB/s-1737kB/s), io=99.6MiB (104MB), run=60092-60092msec


async 760MiB vs sync 1.7MiB
is it normal?


update:
sync=always, ioengine=posixaio:
# fio --directory=/mnt/pool0/sync -direct=1 -iodepth 32 -thread -rw=write -ioengine=posixaio -bs=16k -size=20G -numjobs=6 -runtime=60 -group_reporting -name=mytest mytest: (g=0): rw=write, bs=(R) 16.0KiB-16.0KiB, (W) 16.0KiB-16.0KiB, (T) 16.0KiB-16.0KiB, ioengine=posixaio, iodepth=32 ... fio-3.19 Starting 6 threads mytest: Laying out IO file (1 file / 20480MiB) mytest: Laying out IO file (1 file / 20480MiB) mytest: Laying out IO file (1 file / 20480MiB) mytest: Laying out IO file (1 file / 20480MiB) mytest: Laying out IO file (1 file / 20480MiB) mytest: Laying out IO file (1 file / 20480MiB) Jobs: 6 (f=6): [W(6)][100.0%][w=6583KiB/s][w=411 IOPS][eta 00m:00s] mytest: (groupid=0, jobs=6): err= 0: pid=100794: Tue Feb 9 17:34:51 2021 write: IOPS=487, BW=7793KiB/s (7980kB/s)(459MiB/60312msec) slat (usec): min=2, max=811, avg= 6.21, stdev=13.09 clat (msec): min=135, max=799, avg=393.09, stdev=115.75 lat (msec): min=135, max=799, avg=393.10, stdev=115.75 clat percentiles (msec): | 1.00th=[ 176], 5.00th=[ 213], 10.00th=[ 241], 20.00th=[ 296], | 30.00th=[ 326], 40.00th=[ 359], 50.00th=[ 388], 60.00th=[ 422], | 70.00th=[ 451], 80.00th=[ 489], 90.00th=[ 542], 95.00th=[ 600], | 99.00th=[ 693], 99.50th=[ 726], 99.90th=[ 768], 99.95th=[ 768], | 99.99th=[ 785] bw ( KiB/s): min= 3100, max=15730, per=100.00%, avg=7935.24, stdev=478.46, samples=694 iops : min= 190, max= 980, avg=492.81, stdev=29.92, samples=694 lat (msec) : 250=11.92%, 500=70.67%, 750=17.18%, 1000=0.23% cpu : usr=0.05%, sys=0.65%, ctx=44987, majf=0, minf=0 IO depths : 1=0.3%, 2=1.2%, 4=6.6%, 8=23.0%, 16=60.5%, 32=8.5%, >=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=96.0%, 8=1.0%, 16=0.1%, 32=2.8%, 64=0.0%, >=64=0.0% issued rwts: total=0,29374,0,0 short=0,0,0,0 dropped=0,0,0,0 latency : target=0, window=0, percentile=100.00%, depth=32 Run status group 0 (all jobs): WRITE: bw=7793KiB/s (7980kB/s), 7793KiB/s-7793KiB/s (7980kB/s-7980kB/s), io=459MiB (481MB), run=60312-60312msec
 
Last edited:
Top