From: Ming Lei <ming.lei@redhat.com>
To: Andrea Vai <andrea.vai@unipv.it>
Cc: 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>, Omar Sandoval <osandov@fb.com>,
"Martin K. Petersen" <martin.petersen@oracle.com>,
Greg KH <gregkh@linuxfoundation.org>,
Alan Stern <stern@rowland.harvard.edu>
Subject: Re: Slow I/O on USB media after commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
Date: Wed, 10 Jul 2019 10:44:40 +0800 [thread overview]
Message-ID: <20190710024439.GA2621@ming.t460p> (raw)
In-Reply-To: <20190709211838.GA9645@brian.unipv.it>
On Tue, Jul 09, 2019 at 11:18:38PM +0200, Andrea Vai wrote:
> On 08/07/19 09:01:35, Ming Lei wrote:
> > > > > > > > >
> > > > > > > > > commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
> > > > > > > > >
> > > > > > > > > [...]
> >
> > 1) run the bcc biosnoop trace in one terminal after mounting the fs on the USB dirve
> >
> > 2) start the write test in another teminal
> >
> > 3) wait for 10 seconds, and stop the bcc trace via ctrl^ + C, then post the bcc biosnoop
> > trace log
> >
>
> Done, attached.
>
> Thanks,
> Andrea
> 5.420198000 jbd2/sdf1-8 6775 sdf W 29624320 4096 0.37
> 5.423601000 jbd2/sdf1-8 6775 sdf W 29624328 12288 3.29
> 5.424009000 jbd2/sdf1-8 6775 sdf W 29624352 4096 0.30
> 6.665732000 kworker/u8:0 6401 sdf R 10248 4096 841.64
> 6.666891000 kworker/u8:0 6401 sdf R 10256 4096 0.98
> 6.668141000 kworker/u8:0 6401 sdf R 4196352 4096 1.07
> 6.669312000 kworker/u8:0 6401 sdf R 8390656 4096 0.99
> 6.670568000 kworker/u8:0 6401 sdf R 12584960 4096 1.06
> 6.674257000 kworker/u8:0 6401 sdf R 16779264 4096 3.50
> 6.675510000 kworker/u8:0 6401 sdf R 20973568 4096 1.06
> 6.678344000 kworker/u8:0 6401 sdf R 25167872 4096 2.64
> 6.680384000 kworker/u8:0 6401 sdf R 29362176 4096 1.83
> 6.681622000 kworker/u8:0 6401 sdf R 33556480 4096 1.03
> 6.682713000 kworker/u8:0 6401 sdf R 37750784 4096 0.92
> 6.686360000 kworker/u8:0 6401 sdf R 41945088 4096 3.48
> 6.687589000 kworker/u8:0 6401 sdf R 46139392 4096 1.04
> 6.688639000 kworker/u8:0 6401 sdf R 46139424 4096 0.88
> 6.766336000 kworker/u8:0 6401 sdf W 47351808 122880 77.17
> 6.773563000 kworker/u8:0 6401 sdf W 47352048 122880 7.08
> 6.780980000 kworker/u8:0 6401 sdf W 47352288 122880 7.29
> 6.786366000 kworker/u8:0 6401 sdf W 47352528 122880 5.27
> 6.793831000 kworker/u8:0 6401 sdf W 47352768 122880 7.38
> 6.801085000 kworker/u8:0 6401 sdf W 47353008 122880 7.20
> 6.808405000 kworker/u8:0 6401 sdf W 47353248 122880 7.27
> 6.813799000 kworker/u8:0 6401 sdf W 47353488 122880 5.35
> 6.821103000 kworker/u8:0 6401 sdf W 47353728 118784 7.25
> 6.828459000 kworker/u8:0 6401 sdf W 47353960 122880 7.09
> 6.835722000 kworker/u8:0 6401 sdf W 47354200 122880 7.20
> 6.842813000 kworker/u8:0 6401 sdf W 47354440 122880 7.05
> 6.850184000 kworker/u8:0 6401 sdf W 47354680 122880 7.32
> 6.857452000 kworker/u8:0 6401 sdf W 47354920 122880 7.22
> 6.864874000 kworker/u8:0 6401 sdf W 47355160 122880 7.38
> 6.871841000 kworker/u8:0 6401 sdf W 47355400 122880 6.92
> 6.879380000 kworker/u8:0 6401 sdf W 47355640 122880 7.50
> 6.886497000 kworker/u8:0 6401 sdf W 47355880 122880 7.04
> 6.893940000 kworker/u8:0 6401 sdf W 47356120 122880 7.40
> 6.899304000 kworker/u8:0 6401 sdf W 47356360 122880 5.33
> 6.906635000 kworker/u8:0 6401 sdf W 47356600 122880 7.29
> 6.913957000 kworker/u8:0 6401 sdf W 47356840 122880 7.29
> 6.921308000 kworker/u8:0 6401 sdf W 47357080 122880 7.31
> 6.924391000 kworker/u8:0 6401 sdf W 47357320 53248 3.03
> 6.931971000 kworker/u8:0 6401 sdf W 47357424 122880 7.22
> 6.939169000 kworker/u8:0 6401 sdf W 47357664 122880 7.14
> 6.944985000 kworker/u8:0 6401 sdf W 47357904 122880 5.76
> 6.952113000 kworker/u8:0 6401 sdf W 47358144 122880 7.06
> 6.959608000 kworker/u8:0 6401 sdf W 47358384 122880 7.45
> 6.966820000 kworker/u8:0 6401 sdf W 47358624 122880 7.16
> 6.972393000 kworker/u8:0 6401 sdf W 47358864 122880 5.53
> 6.979550000 kworker/u8:0 6401 sdf W 47359104 122880 7.09
> 6.986879000 kworker/u8:0 6401 sdf W 47359344 122880 7.28
> 6.994306000 kworker/u8:0 6401 sdf W 47359584 122880 7.40
> 7.001338000 kworker/u8:0 6401 sdf W 47359824 122880 6.98
> 7.008740000 kworker/u8:0 6401 sdf W 47360064 122880 7.37
> 7.016114000 kworker/u8:0 6401 sdf W 47360304 122880 7.31
> 7.023546000 kworker/u8:0 6401 sdf W 47360544 122880 7.39
> 7.030437000 kworker/u8:0 6401 sdf W 47360784 122880 6.82
> 7.037834000 kworker/u8:0 6401 sdf W 47361024 122880 7.35
> 7.045224000 kworker/u8:0 6401 sdf W 47361264 122880 7.32
> 7.052687000 kworker/u8:0 6401 sdf W 47361504 122880 7.39
> 7.057977000 kworker/u8:0 6401 sdf W 47361744 122880 5.01
> 7.065390000 kworker/u8:0 6401 sdf W 47361984 122880 7.35
> 7.072749000 kworker/u8:0 6401 sdf W 47362224 122880 7.28
> 7.080174000 kworker/u8:0 6401 sdf W 47362464 122880 7.36
> 7.085335000 kworker/u8:0 6401 sdf W 47362704 122880 5.08
> 7.092881000 kworker/u8:0 6401 sdf W 47362944 122880 7.50
> 7.100197000 kworker/u8:0 6401 sdf W 47363184 122880 7.23
> 7.107507000 kworker/u8:0 6401 sdf W 47363424 122880 7.24
> 7.114684000 kworker/u8:0 6401 sdf W 47363664 122880 7.09
> 7.121936000 kworker/u8:0 6401 sdf W 47363904 122880 7.18
> 7.129299000 kworker/u8:0 6401 sdf W 47364144 122880 7.29
> 7.136645000 kworker/u8:0 6401 sdf W 47364384 122880 7.27
> 7.143733000 kworker/u8:0 6401 sdf W 47364624 122880 7.02
> 7.151112000 kworker/u8:0 6401 sdf W 47364864 122880 7.31
> 7.158509000 kworker/u8:0 6401 sdf W 47365104 122880 7.33
> 7.165735000 kworker/u8:0 6401 sdf W 47365344 122880 7.14
> 7.171205000 kworker/u8:0 6401 sdf W 47365584 122880 5.40
> 7.178625000 kworker/u8:0 6401 sdf W 47365824 122880 7.37
> 7.185980000 kworker/u8:0 6401 sdf W 47366064 122880 7.31
> 7.193593000 kworker/u8:0 6401 sdf W 47366304 122880 7.57
> 7.198674000 kworker/u8:0 6401 sdf W 47366544 122880 5.02
> 7.205996000 kworker/u8:0 6401 sdf W 47366784 122880 7.25
> 7.213419000 kworker/u8:0 6401 sdf W 47367024 122880 7.37
> 7.221005000 kworker/u8:0 6401 sdf W 47367264 122880 7.52
> 7.227906000 kworker/u8:0 6401 sdf W 47367504 122880 6.83
> 7.235251000 kworker/u8:0 6401 sdf W 47367744 122880 7.28
> 7.241892000 kworker/u8:0 6401 sdf W 47367984 106496 6.59
> 7.249617000 kworker/u8:0 6401 sdf W 47368192 122880 6.88
> 7.256892000 kworker/u8:0 6401 sdf W 47368432 122880 7.20
> 7.264223000 kworker/u8:0 6401 sdf W 47368672 122880 7.26
> 7.269672000 kworker/u8:0 6401 sdf W 47368912 122880 5.39
> 7.277066000 kworker/u8:0 6401 sdf W 47369152 122880 7.36
> 7.284630000 kworker/u8:0 6401 sdf W 47369392 122880 7.52
> 7.291891000 kworker/u8:0 6401 sdf W 47369632 122880 7.20
> 7.297211000 kworker/u8:0 6401 sdf W 47369872 122880 5.29
> 7.304665000 kworker/u8:0 6401 sdf W 47370112 122880 7.41
> 7.312050000 kworker/u8:0 6401 sdf W 47370352 122880 7.33
> 7.319520000 kworker/u8:0 6401 sdf W 47370592 122880 7.41
> 7.326494000 kworker/u8:0 6401 sdf W 47370832 122880 6.89
> 7.334082000 kworker/u8:0 6401 sdf W 47371072 122880 7.52
> 7.341505000 kworker/u8:0 6401 sdf W 47371312 122880 7.34
> 7.348600000 kworker/u8:0 6401 sdf W 47371552 122880 7.01
> 7.355806000 kworker/u8:0 6401 sdf W 47371792 122880 7.16
> 7.363147000 kworker/u8:0 6401 sdf W 47372032 122880 7.27
> 7.370377000 kworker/u8:0 6401 sdf W 47372272 122880 7.16
> 7.377770000 kworker/u8:0 6401 sdf W 47372512 122880 7.36
> 7.383323000 kworker/u8:0 6401 sdf W 47372752 122880 5.50
> 7.390651000 kworker/u8:0 6401 sdf W 47372992 122880 7.27
> 7.398245000 kworker/u8:0 6401 sdf W 47373232 122880 7.52
> 7.405347000 kworker/u8:0 6401 sdf W 47373472 122880 7.04
> 7.410761000 kworker/u8:0 6401 sdf W 47373712 122880 5.36
> 7.418075000 kworker/u8:0 6401 sdf W 47373952 122880 7.26
> 7.425451000 kworker/u8:0 6401 sdf W 47374192 122880 7.33
> 7.432864000 kworker/u8:0 6401 sdf W 47374432 122880 7.36
> 7.439913000 kworker/u8:0 6401 sdf W 47374672 122880 6.99
> 7.447312000 kworker/u8:0 6401 sdf W 47374912 122880 7.35
> 7.454721000 kworker/u8:0 6401 sdf W 47375152 122880 7.35
> 7.461955000 kworker/u8:0 6401 sdf W 47375392 122880 7.19
> 7.469040000 kworker/u8:0 6401 sdf W 47375632 122880 7.04
> 7.476416000 kworker/u8:0 6401 sdf W 47375872 122880 7.31
> 7.483856000 kworker/u8:0 6401 sdf W 47376112 122880 7.38
> 7.491270000 kworker/u8:0 6401 sdf W 47376352 122880 7.37
> 7.496452000 kworker/u8:0 6401 sdf W 47376592 122880 5.12
> 7.504011000 kworker/u8:0 6401 sdf W 47376832 122880 7.52
> 7.511217000 kworker/u8:0 6401 sdf W 47377072 122880 7.12
> 7.518511000 kworker/u8:0 6401 sdf W 47377312 122880 7.23
> 7.523956000 kworker/u8:0 6401 sdf W 47377552 122880 5.41
> 7.531197000 kworker/u8:0 6401 sdf W 47377792 122880 7.21
> 7.538546000 kworker/u8:0 6401 sdf W 47378032 122880 7.31
> 7.545757000 kworker/u8:0 6401 sdf W 47378272 122880 7.17
> 7.552919000 kworker/u8:0 6401 sdf W 47378512 122880 7.13
> 7.560269000 kworker/u8:0 6401 sdf W 47378752 122880 7.31
> 7.567555000 kworker/u8:0 6401 sdf W 47378992 122880 7.25
> 7.574863000 kworker/u8:0 6401 sdf W 47379232 122880 7.27
> 7.581802000 kworker/u8:0 6401 sdf W 47379472 122880 6.87
> 7.588979000 kworker/u8:0 6401 sdf W 47379712 122880 7.13
> 7.596343000 kworker/u8:0 6401 sdf W 47379952 122880 7.30
> 7.603224000 kworker/u8:0 6401 sdf W 47380192 122880 6.84
> 7.608655000 kworker/u8:0 6401 sdf W 47380432 122880 5.38
> 7.615811000 kworker/u8:0 6401 sdf W 47380672 122880 7.12
> 7.623028000 kworker/u8:0 6401 sdf W 47380912 122880 7.18
> 7.630413000 kworker/u8:0 6401 sdf W 47381152 122880 7.34
> 7.635223000 kworker/u8:0 6401 sdf W 47381392 122880 4.75
> 7.642268000 kworker/u8:0 6401 sdf W 47381632 122880 6.98
> 7.649383000 kworker/u8:0 6401 sdf W 47381872 122880 7.04
> 7.656619000 kworker/u8:0 6401 sdf W 47382112 122880 7.19
> 7.661918000 kworker/u8:0 6401 sdf W 47382352 122880 5.25
> 8.268039000 kworker/u8:0 6401 sdf W 47382592 122880 606.07
> 8.280414000 kworker/u8:0 6401 sdf W 47382832 122880 12.30
> 8.286503000 kworker/u8:0 6401 sdf W 47383072 122880 6.02
> 8.293627000 kworker/u8:0 6401 sdf W 47383312 122880 7.07
> 8.300777000 kworker/u8:0 6401 sdf W 47383552 122880 7.08
> 8.307733000 kworker/u8:0 6401 sdf W 47383792 122880 6.89
> 8.315212000 kworker/u8:0 6401 sdf W 47384032 122880 7.43
> 8.320697000 kworker/u8:0 6401 sdf W 47384272 122880 5.41
> 8.323335000 kworker/u8:0 6401 sdf W 47384512 32768 2.58
> 8.331116000 kworker/u8:0 6401 sdf W 47384576 122880 6.58
> 8.338586000 kworker/u8:0 6401 sdf W 47384816 122880 7.40
> 8.346113000 kworker/u8:0 6401 sdf W 47385056 122880 7.46
> 8.351558000 kworker/u8:0 6401 sdf W 47385296 122880 5.37
> 8.359030000 kworker/u8:0 6401 sdf W 47385536 122880 7.43
> 8.366425000 kworker/u8:0 6401 sdf W 47385776 122880 7.34
> 8.373712000 kworker/u8:0 6401 sdf W 47386016 122880 7.22
> 8.940689000 cp 6828 sdf W 47400960 122880 566.92
> 9.614647000 kworker/u8:0 6401 sdf W 47386256 122880 673.87
> 10.179120000 cp 6828 sdf W 47401200 122880 564.38
5 of 165 IO requests(1 4096 READ and 4 120K WRITE) take more than 500ms, and
most of others only needs <10ms. That is the reason why the performance
drops, and it is highly related with your USB pen drive.
biosnoop collects the trace data in blk_mq_start_request() and
blk_account_io_completion(), both happens during dispatching request to
LLD & device.
From my understanding, scsi-mq should only change the timing, or maybe
some setting is changed(still very unlikely), you may follow Alan's suggestion
to collect usbmon on 'bad' & 'good' kernel, and check if the setting is
changed.
If the initialization setting is same, maybe you can try US_FL_GO_SLOW
quirk.
Thanks,
Ming
next prev parent reply other threads:[~2019-07-10 2:44 UTC|newest]
Thread overview: 77+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-07-02 10:46 Slow I/O on USB media after commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6 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
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 [this message]
[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
2019-09-18 15:25 ` Andrea Vai
2019-09-18 16:30 ` Alan Stern
2019-09-19 7:33 ` Andrea Vai
2019-09-19 17:54 ` Alan Stern
2019-09-20 7:25 ` Andrea Vai
2019-09-20 7:44 ` Greg KH
2019-09-19 8:26 ` Damien Le Moal
2019-09-19 8:55 ` Ming Lei
2019-09-19 9:09 ` Damien Le Moal
2019-09-19 9:21 ` Ming Lei
2019-09-19 14:01 ` Alan Stern
2019-09-19 14:14 ` Damien Le Moal
2019-09-20 7:03 ` Andrea Vai
2019-09-25 19:30 ` Alan Stern
2019-09-25 19:36 ` Jens Axboe
2019-09-27 15:47 ` Andrea Vai
2019-11-04 16:00 ` Andrea Vai
2019-11-04 18:20 ` Alan Stern
2019-11-05 11:48 ` Andrea Vai
2019-11-05 18:31 ` Alan Stern
2019-11-05 23:29 ` Jens Axboe
2019-11-06 16:03 ` Alan Stern
2019-11-06 22:13 ` Damien Le Moal
2019-11-07 7:04 ` Andrea Vai
2019-11-07 7:54 ` Damien Le Moal
2019-11-07 18:59 ` Andrea Vai
2019-11-08 8:42 ` Damien Le Moal
2019-11-08 14:33 ` Jens Axboe
2019-11-11 10:46 ` Andrea Vai
2019-11-09 10:09 ` Ming Lei
2019-11-09 22:28 ` Ming Lei
2019-11-11 10:50 ` Andrea Vai
2019-11-11 11:05 ` Ming Lei
2019-11-11 11:13 ` Andrea Vai
2019-11-22 19:16 ` Andrea Vai
2019-11-23 7:28 ` Ming Lei
2019-11-23 15:44 ` Andrea Vai
2019-11-25 3:54 ` Ming Lei
2019-11-25 10:11 ` Andrea Vai
2019-11-25 10:29 ` Ming Lei
2019-11-25 14:58 ` Andrea Vai
2019-11-25 15:15 ` Ming Lei
2019-11-25 18:51 ` Andrea Vai
2019-11-26 2:32 ` Ming Lei
2019-11-26 7:46 ` Andrea Vai
2019-11-26 9:15 ` Ming Lei
2019-11-26 10:24 ` Ming Lei
2019-11-26 11:14 ` Andrea Vai
2019-11-27 2:05 ` Ming Lei
2019-11-27 9:39 ` Andrea Vai
2019-11-27 13:08 ` Ming Lei
2019-11-27 15:01 ` Andrea Vai
2019-11-27 0:21 ` Finn Thain
2019-11-28 17:10 ` Andrea Vai
Reply instructions:
You may reply publicly 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=20190710024439.GA2621@ming.t460p \
--to=ming.lei@redhat.com \
--cc=andrea.vai@unipv.it \
--cc=axboe@kernel.dk \
--cc=gregkh@linuxfoundation.org \
--cc=hare@suse.com \
--cc=himanshu.madhani@cavium.com \
--cc=linux-scsi@vger.kernel.org \
--cc=linux-usb@vger.kernel.org \
--cc=martin.petersen@oracle.com \
--cc=osandov@fb.com \
--cc=stern@rowland.harvard.edu \
/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
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).