Il giorno lun 26 ago 2019 alle ore 18:33 Alan Stern < stern@xxxxxxxxxxxxxxxxxxx> ha scritto: > [...] > 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. ok, I performed 10 tests for each kernel, so we have 20 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. ok, so I duplicated the tests above for the "64" case (it was initially set as "120", if it is relevant to know), leading to 40 tests named as bad.mon.out_50000000_64_TIMESTAMP bad.mon.out_50000000_non64_TIMESTAMP good.mon.out_50000000_64_TIMESTAMP good.mon.out_50000000_non64_TIMESTAMP where "64" denotes the ones done with that value in max_sectors_kb, and "not64" the ones without it (as far as I can tell, it has been always "120"). So, we have 40 traces total. Each set of 10 trials is identified by a text file, which contains the output log of the test script (and the timestamps), also available in the download zipfile. Just to summarize here the times, they are respectively (number expressed in seconds): BAD: Logs: log_10trials_50MB_BAD_NonCanc_64.txt, log_10trials_50MB_BAD_NonCanc_non64.txt 64: 34, 34, 35, 39, 37, 32, 42, 44, 43, 40 not64: 61, 71, 59, 71, 62, 75, 62, 70, 62, 68 GOOD: Logs: log_10trials_50MB_GOOD_NonCanc_64.txt, log_10trials_50MB_GOOD_NonCanc_non64.txt 64: 34, 32, 35, 34, 35, 33, 34, 33, 33, 33 not64: 32, 30, 32, 31, 31, 30, 32, 30, 32, 31 Finally, one note about the workaround proposed by Alan, "delete the file before copying". My original problem occurred while using a backup software (dar - see http://dar.linux.free.fr/). So, I tried now to do the backup by deleting the existing file beforehand, and it still takes a lot of time with bad kernel: a 900 file backup takes ~160sec with GOOD kernel, and >40min with BAD kernel. I also tried the "64" tweak in the BAD kernel and it becomes ~300s. Then, I also tried the "64" case with good kernel, and became ~140s. Detailed data: GOOD (not "64): 155s, 151s GOOD ("64"): 142s, 141s BAD (not "64"): 47minutes, 43minutes BAD ("64"): 315s, 288s, 268s, 239s, 302s The command ran is: $ SECONDS=0; rm /run/media/andrea/BAK_ANDVAI/aero.1.dar && dar -c /run/media/andrea/BAK_ANDVAI/aero -R /home/andrea/Musica/MP3/Aerosmith && umount /run/media/andrea/BAK_ANDVAI; echo "Ci ho messo: $SECONDS secondi." Speculations: - It seems the "64" value plays a role, more evident on "bad" kernels (~halves the time) and less (but still existing?) on "good" kernels; - dar with the bad kernel, with the "delete beforehand" action, is still an order of magnitude slower than with the good kernel (so, it behaves the same way as in the "overwrite" case). Maybe it depends on the way dar itself writes data... I don't know if you can understand it, or we should ask for a light to the dar developer(s) about it. You can grab the traces at http://fisica.unipv.it/transfer/usbmon_logs_2.zip Thanks, and bye Andrea
