Re: Slow I/O on USB media after commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6

Alan Stern
2019-08-26T16:33:23Z

On Mon, 26 Aug 2019, Andrea Vai wrote:

> ok, so you can grab them at
>
> http://fisica.unipv.it/transfer/usbmon_logs.zip
>
> (they will be automatically removed from there in a couple of weeks).
>
> For each size there is a .txt file (which contains the terminal
> output) and 10 bad.mon.out_.... trace files. The file suffix "NonCanc"
> means there has not been file deletion before copy; while "Canc" means
> the opposite.
>
> Each trace file name is identified by a timestamp that is also
> referenced inside the txt, so if you want to get i.e. the 39-sec trial
> for the 10MB filesize you have to open the ...10MB....txt, search for
> the 39 seconds total time string ("Dopo stop trace: 39"), look at the
> beginning of that trial, a dozen rows before, take note of the
> timestamp, and open the corresponding bad.mon.out file (of course, if
> there are more trials with the same time, you have to identify it by
> counting its position (7th in the example above)).
>
> To make it more simple:
>
> $ seconds=39; size=10MB; grep -B14 "Dopo stop trace: $seconds" log_10trials_"$size"_NonCanc.txt
>
> should show you more straightly the part(s) you need.
>
> > Odd that the delays never occur when you're writing a new file. (If
> > nothing else, that gives you a way to work around the problem!)
>
> Thank you, didn't realize that :-) I will try it.

In fact, even the traces where the file doesn't exist beforehand show
some delays. Just not as many delays as the traces where the file does
exist. And again, each delay is in the middle of a write command, not
between commands.

I suppose changes to the upper software layers could affect which
blocks are assigned when a new file is written. Perhaps one kernel
re-uses the same old blocks that had been previously occupied and the
other kernel allocates a completely new set of blocks. That might
change the drive's behavior. The quick way to tell is to record two
usbmon traces, one under the "good" kernel and one under the "bad"
kernel, where each test involves writing over a file that already
exists (say, 50 MB) -- the same file for both tests. The block numbers
will appear in the traces.

Also, I wonder if the changing the size of the data transfers would
make any difference. This is easy to try; just write "64" to
/sys/block/sd?/queue/max_sectors_kb (where the ? is the appropriate
drive letter) after the drive is plugged in but before the test starts.

Alan Stern