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

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <e852331e72532dbfdc7981d958b1cd05ded41317.camel@unipv.it>
Date:   Tue, 26 Nov 2019 12:14:19 +0100
From:   Andrea Vai <andrea.vai@...pv.it>
To:     Ming Lei <ming.lei@...hat.com>
Cc:     Damien Le Moal <Damien.LeMoal@....com>,
        Alan Stern <stern@...land.harvard.edu>,
        Jens Axboe <axboe@...nel.dk>,
        Johannes Thumshirn <jthumshirn@...e.de>,
        USB list <linux-usb@...r.kernel.org>,
        SCSI development list <linux-scsi@...r.kernel.org>,
        Himanshu Madhani <himanshu.madhani@...ium.com>,
        Hannes Reinecke <hare@...e.com>,
        Omar Sandoval <osandov@...com>,
        "Martin K. Petersen" <martin.petersen@...cle.com>,
        Greg KH <gregkh@...uxfoundation.org>,
        Hans Holmberg <Hans.Holmberg@....com>,
        Kernel development list <linux-kernel@...r.kernel.org>
Subject: Re: Slow I/O on USB media after commit
 f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6

Il giorno mar, 26/11/2019 alle 17.15 +0800, Ming Lei ha scritto:
> On Tue, Nov 26, 2019 at 08:46:07AM +0100, Andrea Vai wrote:
> > Il giorno mar, 26/11/2019 alle 10.32 +0800, Ming Lei ha scritto:
> > > On Mon, Nov 25, 2019 at 07:51:33PM +0100, Andrea Vai wrote:
> > > > Il giorno lun, 25/11/2019 alle 23.15 +0800, Ming Lei ha
> scritto:
> > > > > On Mon, Nov 25, 2019 at 03:58:34PM +0100, Andrea Vai wrote:
> > > > > 
> > > > > [...]
> > > > > 
> > > > > > What to try next?
> > > > > 
> > > > > 1) cat /sys/kernel/debug/block/$DISK/hctx0/flags
> > > > result:
> > > > 
> > > > alloc_policy=FIFO SHOULD_MERGE|2
> > > > 
> > > > > 
> > > > > 
> > > > > 2) echo 128 > /sys/block/$DISK/queue/nr_requests and run
> your
> > > copy
> > > > > 1GB
> > > > > test again.
> > > > 
> > > > done, and still fails. What to try next?
> > > 
> > > I just run 256M cp test
> > 
> > I would like to point out that 256MB is a filesize that usually
> don't
> > trigger the issue (don't know if it matters, sorry).
> 
> OK.
> 
> I tested 256M because IO timeout is often triggered in case of
> qemu-ehci, and it is a long-term issue. When setting up the disk
> via xhci-qemu, the max request size is increased to 1MB from 120KB,
> and IO pattern changed too. When the disk is connected via uhci-
> qemu,
> the transfer is too slow(1MB/s) because max endpoint size is too
> small.
> 
> However, I just waited 16min and collected all the 1GB IO log by
> connecting disk over uhci-qemu, but the sector of each data IO
> is still in order.
> 
> > 
> > Another info I would provide is about another strange behavior I
> > noticed: yesterday I ran the test two times (as usual with 1GB
> > filesize) and took 2370s, 1786s, and a third test was going on
> when I
> > stopped it. Then I started another set of 100 trials and let them
> run
> > tonight, and the first 10 trials were around 1000s, then gradually
> > decreased to ~300s, and finally settled around 200s with some
> trials
> > below 70-80s. This to say, times are extremely variable and for
> the
> > first time I noticed a sort of "performance increase" with time.
> 
> The 'cp' test is buffered IO, can you reproduce it every time by
> running copy just after fresh mount on the USB disk?

yes, every time my test script (attached) mounts, copy, unmount (but I
don't unplug and replug the pendrive each time). Is this enough?

> 
> > 
> > >  to one USB storage device on patched kernel,
> > > and WRITE data IO is really in ascending order. The filesystem
> is
> > > ext4,
> > > and mount without '-o sync'. From previous discussion, looks
> that is
> > > exactly your test setting. The order can be observed via the
> > > following script:
> > > 
> > > #!/bin/sh
> > > MAJ=$1
> > > MIN=$2
> > > MAJ=$(( $MAJ << 20 ))
> > > DEV=$(( $MAJ | $MIN ))
> > > /usr/share/bcc/tools/trace -t -C \
> > >   't:block:block_rq_issue (args->dev == '$DEV') "%s %d %d",
> args-
> > > >rwbs, args->sector, args->nr_sector'
> > > 
> > > $MAJ & $MIN can be retrieved via lsblk for your USB storage
> disk.

ok, so I try:

# lsblk /dev/sdf
NAME   MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
sdf      8:80   1 28,8G  0 disk 
└─sdf1   8:81   1 28,8G  0 part 

so I ran your script (the second one, which you sent me in the next
email message) with:

./test_ming 8 80

but it fails to run (terminal output is in attached errors.txt).
What am I doing wrong?

It's still not clear to me if I need to start the trace script and
then the test, or the opposite (or doesn't matter). The above errors
are in the former case (I didn't even start the test, actually)

Thanks,
Andrea

View attachment "errors.txt" of type "text/plain" (60490 bytes)

Download attachment "test" of type "application/x-shellscript" (1080 bytes)