From: Sworddragon <[email-masked]>
Date: Thu, 28 Oct 2021 21:59:06 +0000

Despite I'm not using Linux as main system anymore and wanted to avoid
getting into too much work I found some time to do some tests as this issue
bugs me just too much.

> You could try running the following immediately after,
> to see if it also returns quickly:
>
>   blockdev --flushbufs /dev/sdb

Yes, this command also blocks for a bit over 1 minute when this issue
occurs. Here is the output (I had to freely translate the strings since
this Knoppix instance is only in german so they might be slightly
inaccurate; Also I had to type all text since it was executed on a
different system but carefully checked to not introduce any typos):

root@Microknoppix:~# dd if=/dev/random of=/dev/sdb bs=1M conv=fsync
status=progress
1039138816 Bytes(1,0 GB, 991 MiB) copied, 56 s, 18,5 MB/s
dd: Error on writing '/dev/sdb': The device has not enough free space
999+0 records in
998+0 records out
1047526912 Bytes (1,0 GB, 999 MiB) copied, 57,0283 s, 18,4 MB/s
root@Microknoppix:~# time blockdev --flushbufs /dev/sdb

real    1m9,747s
user    0m0,001s
sys     0m0,005s

(A bit offtopic, but maybe another minor bug: The first line of the copied
bytes differ slightly with every attempt (like 991 MiB, 994 MiB, 997 MiB,
etc.) but the last line seems to be always the same up to the last byte. I
had the impression the output from status=progress does not do a final
update once dd throws the writing error because the free space went out, is
my assumption correct? If so, it would probably make sense and be helpful
for others on debugging attempts if dd would do a final update. But back to
the original topic)

> Also with rates status.
>
>     dd if=/dev/random of=/dev/sdb bs=1M oflag=direct status=progress

With conv=fsync the bug usually occurs every 3-4 attempts (but the sample
size is small) so I decided to do 20 attempts with oflag=direct. The issue
did not appear once and every attempt was roughly 129 seconds (+/- 0.5
seconds) and an executed sync afterwards always returned immediately. Does
direct I/O signal the related storage device to not use its bultin-cache?
If not this implies that the USB Thumb Drive's firmware is very likely not
faulty and does not contribute to this issue.

But I noticed some other thing (I also noticed it in the past but it got
now my attention after all the stable oflag=direct writes): With conv=fsync
the writing time is sometimes around double as high as it should be. On
doing now 3 attempts with it dd showed me final times of 244,382s, 239,127s
and 135,389s, while the status progress always stopped after 56s. So
waiting for the buffers to be flushed after dd claimed about no free empty
storage space the times differ very significantly at best roughly as fast
as oflag=direct and at worst ~2.5 times slower than they should be.

To sum this up we have 2 issues:

1. The status progress from status=progress does not make a final update
(which would be useful) - but that is offtopic and probably easy to fix so
I guess there is no more for me to do here.
2. fsync returns often either early when the buffers are not fully flushed
yet or it drastically increases the writing time compared to normal
attempts (even the normal attempts are apparently quite a bit slower than
direct I/O while probably the opposite should be the case) which is very
likely either a bug in dd or something in the Linux Kernel's fsync()
imlementation is very broken.