Linux-USB Archive on lore.kernel.org
 help / color / Atom feed
From: Alan Stern <stern@rowland.harvard.edu>
To: Andrea Vai <andrea.vai@unipv.it>
Cc: Johannes Thumshirn <jthumshirn@suse.de>,
	Jens Axboe <axboe@kernel.dk>, <linux-usb@vger.kernel.org>,
	<linux-scsi@vger.kernel.org>,
	Himanshu Madhani <himanshu.madhani@cavium.com>,
	Hannes Reinecke <hare@suse.com>, Ming Lei <ming.lei@redhat.com>,
	Omar Sandoval <osandov@fb.com>,
	"Martin K. Petersen" <martin.petersen@oracle.com>,
	Greg KH <gregkh@linuxfoundation.org>
Subject: Re: Slow I/O on USB media after commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
Date: Mon, 8 Jul 2019 11:38:59 -0400 (EDT)
Message-ID: <Pine.LNX.4.44L0.1907081101260.1424-100000@iolanthe.rowland.org> (raw)
In-Reply-To: <20190706220644.GA9765@brian.unipv.it>

On Sun, 7 Jul 2019, Andrea Vai wrote:

> On 03/07/19 10:23:13, Alan Stern wrote:
> > 
> > [...]
> > Andrea, another thing you could try is to collect a usbmon trace under 
> > one of the "slow" kernels.  Follow the instructions in 
> > Documentation/usb/usbmon.txt.  I think you could kill the file-copy 
> > operation after just a couple of seconds; that should provide enough 
> > trace information to help see what causes the slowdown.
> > 
> > (If you want, do the same test with a "fast" kernel and then we'll 
> > compare the results.)
> > 
> > Alan Stern
> > 
> 
> Thanks Alan,
>   so I attach two ouputs, one for a "good" and one for a "bad" kernel.
> 
> Both killed after roughly 20 seconds, using the command
> 
> cat /sys/kernel/debug/usb/usbmon/6u > file
> 
> (my pendrive turns out to be attached to bus #6)
> 
> Hope it helps.

I don't know what the results mean, but I _can_ tell you what's
happening.  Every so often (at intervals of about a second) the pen
drive completely stops communicating with the "bad" kernel for about
one second and then starts up again.

Here's a short example from the "bad" trace:

ffff9169f0d399c0 513072808 S Bo:6:008:2 -115 122880 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff9169f0d399c0 514262176 C Bo:6:008:2 0 122880 >

The second column is a timestamp (in microseconds).  This little
extract shows a 120-KB write starting at time 513.072 and ending at
514.262, more than a second later.  Normally such a write would
complete in about 0.06 s.

The cumulative effect of all these delays is to slow the transfer 
drastically.  The "good" kernel trace shows a few delays like this, but 
only one or two.

I have no idea how commit f664a3cc17b7, getting rid of the legacy IO 
path, could have caused these delays.  It seems more likely that the 
pen drive itself is the cause, perhaps because it is flushing buffers 
more often under the "bad" kernel.

I'd like you to try doing another pair of usbmon tests.  This time,
start collecting the usbmon trace _before_ you plug in the pen drive,
and stop the trace shortly after the pen drive has been mounted.  
Don't try to transfer any data.  Perhaps the two kernels are
initializing the pen drive with different settings and that accounts
for the different behaviors.

Alan Stern


  reply index

Thread overview: 23+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2019-07-02 10:46 Andrea Vai
2019-07-02 11:51 ` Johannes Thumshirn
2019-07-02 22:36   ` Andrea Vai
2019-07-03  7:29     ` Johannes Thumshirn
2019-07-03 14:23       ` Alan Stern
2019-07-06 22:06         ` Andrea Vai
2019-07-08 15:38           ` Alan Stern [this message]
2019-07-02 12:01 ` Ming Lei
2019-07-02 22:39   ` Andrea Vai
2019-07-03  2:01     ` Ming Lei
2019-07-03  5:11       ` Andrea Vai
2019-07-03  6:36         ` Ming Lei
2019-07-03 15:27           ` Chris Murphy
2019-07-06  9:33           ` Andrea Vai
2019-07-08  1:01             ` Ming Lei
2019-07-09 21:18               ` Andrea Vai
2019-07-10  2:44                 ` Ming Lei
     [not found] <e3f87757f7a0fdf551e911ad32fc8122eebe04c7.camel@unipv.it>
2019-08-13 19:52 ` Alan Stern
     [not found] <307581a490b610c3025ee80f79a465a89d68ed19.camel@unipv.it>
2019-08-20 17:13 ` Alan Stern
2019-08-23 10:39   ` Andrea Vai
2019-08-23 20:42     ` Alan Stern
2019-08-26  6:09       ` Andrea Vai
2019-08-26 16:33         ` Alan Stern

Reply instructions:

You may reply publically to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=Pine.LNX.4.44L0.1907081101260.1424-100000@iolanthe.rowland.org \
    --to=stern@rowland.harvard.edu \
    --cc=andrea.vai@unipv.it \
    --cc=axboe@kernel.dk \
    --cc=gregkh@linuxfoundation.org \
    --cc=hare@suse.com \
    --cc=himanshu.madhani@cavium.com \
    --cc=jthumshirn@suse.de \
    --cc=linux-scsi@vger.kernel.org \
    --cc=linux-usb@vger.kernel.org \
    --cc=martin.petersen@oracle.com \
    --cc=ming.lei@redhat.com \
    --cc=osandov@fb.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

Linux-USB Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-usb/0 linux-usb/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-usb linux-usb/ https://lore.kernel.org/linux-usb \
		linux-usb@vger.kernel.org linux-usb@archiver.kernel.org
	public-inbox-index linux-usb


Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-usb


AGPL code for this site: git clone https://public-inbox.org/ public-inbox