Slow I/O on USB media

Slow I/O on USB media

[Andrea Vai]

Hi,
  I have a problem as described at [1], sorry for misunderstanding the
right place to report it.

The last kernel I can easily install and test was 5.0.17, but please
tell me if I should install a newer version (or anything else I should
do). I just tried installing 5.1.5 but suddenly stopped as I have
problem in compilation (please be patient with me, because I am not an
expert).

Here follows the bug report content:

I am experiencing slow I/O performance since kernel 5.0.1. File
operations are roughly 10 times slower than they used to be using
kernel up to 4.20. The problem is present when I use an USB pendrive,
and does not happen when I copy a file from an internal SATA to
another internal SATA hard disk.

You can see the discussion in the dar (backup software) mailing list
[2], because I first noticed the problem using dar, but then
discovered that also usual file operations such as "cp" suffer the
same problem.

Steps to Reproduce:
Copy a file (e.g. roughly 1GB) from an internal SATA HD to an USB
pendrive using "cp", using kernel 5.0.1+

Actual Results:
The file is copied in about 12 minutes

Expected Results:
The file is copied in about 1 minute (as it happens with kernel up to
4.20.13)

Running Fedora 29 on a Desktop PC.
Kernels found to be affected: e.g. 5.0.7, 5.0.9, 5.0.10, 5.0.13,
5.0.14, 5.0.17.

Thanks, and bye,
Andrea

[1] https://bugzilla.kernel.org/show_bug.cgi?id=203757
[2] https://sourceforge.net/p/dar/mailman/dar-support/thread/d490b5733731cbbb526d759c858a4b11a52fd179.camel%40unipv.it/#msg36660380

Re: Slow I/O on USB media

[Greg KH]

On Thu, May 30, 2019 at 03:18:14PM +0200, Andrea Vai wrote:
> Hi,
>   I have a problem as described at [1], sorry for misunderstanding the
> right place to report it.
> 
> The last kernel I can easily install and test was 5.0.17, but please
> tell me if I should install a newer version (or anything else I should
> do). I just tried installing 5.1.5 but suddenly stopped as I have
> problem in compilation (please be patient with me, because I am not an
> expert).
> 
> Here follows the bug report content:
> 
> I am experiencing slow I/O performance since kernel 5.0.1. File
> operations are roughly 10 times slower than they used to be using
> kernel up to 4.20. The problem is present when I use an USB pendrive,
> and does not happen when I copy a file from an internal SATA to
> another internal SATA hard disk.
> 
> You can see the discussion in the dar (backup software) mailing list
> [2], because I first noticed the problem using dar, but then
> discovered that also usual file operations such as "cp" suffer the
> same problem.
> 
> Steps to Reproduce:
> Copy a file (e.g. roughly 1GB) from an internal SATA HD to an USB
> pendrive using "cp", using kernel 5.0.1+
> 
> Actual Results:
> The file is copied in about 12 minutes
> 
> Expected Results:
> The file is copied in about 1 minute (as it happens with kernel up to
> 4.20.13)
> 
> Running Fedora 29 on a Desktop PC.
> Kernels found to be affected: e.g. 5.0.7, 5.0.9, 5.0.10, 5.0.13,
> 5.0.14, 5.0.17.

Any chance you can use 'git bisect' to find the offending commit?

And did you accidentally turn on "sync" for the filesystem?  How do you
know the old kernel really flushed the buffers out in 1 minute?  But 12
minutes is really long, did anything else change in your userspace
between the kernel changes as well?

thanks,

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> [...]
Hi,

> Any chance you can use 'git bisect' to find the offending commit?
Yes, I am doing it as I managed to build the kernel from source

> 
> And did you accidentally turn on "sync" for the filesystem? 
Sorry, I don't think so but actually I don't know exactly what it is
nor how to check it...

>  How do you
> know the old kernel really flushed the buffers out in 1 minute? 

I used to try to unmount the usb media (e.g. "eject" using Nautilus
file manager), and got a message stating the filesystem was in use and
could not be mounted, so always answered to not eject it until it was
unmounted without any warning... does it make sense?

>  But 12
> minutes is really long, did anything else change in your userspace
> between the kernel changes as well?
I am not sure if I understand correctly the "userspace" you mention:
if you mean my home directory and contents, settings etc, then yes,
maybe... but while I am doing the tests I am quite sure I didn't
change anything, and double-checked many times that the 4.20 kernel is
always working (I usually boot up with it when I need to do the usual
day work).

Thank you for any further explanation,

Bye
Andrea

Re: Slow I/O on USB media

[Greg KH]

On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> > [...]
> Hi,
> 
> > Any chance you can use 'git bisect' to find the offending commit?
> Yes, I am doing it as I managed to build the kernel from source

Great!  What did you find?

> > And did you accidentally turn on "sync" for the filesystem? 
> Sorry, I don't think so but actually I don't know exactly what it is
> nor how to check it...
> 
> >  How do you
> > know the old kernel really flushed the buffers out in 1 minute? 
> 
> I used to try to unmount the usb media (e.g. "eject" using Nautilus
> file manager), and got a message stating the filesystem was in use and
> could not be mounted, so always answered to not eject it until it was
> unmounted without any warning... does it make sense?

That does not mean that the data is not flushed to the device yet, that
just means that some userspace program is still accessing the device.
You need to run some other type of test to validate how long it taks for
the data to get to the device.

> >  But 12
> > minutes is really long, did anything else change in your userspace
> > between the kernel changes as well?
> I am not sure if I understand correctly the "userspace" you mention:
> if you mean my home directory and contents, settings etc, then yes,
> maybe... but while I am doing the tests I am quite sure I didn't
> change anything, and double-checked many times that the 4.20 kernel is
> always working (I usually boot up with it when I need to do the usual
> day work).

I mean, did any other programs on your machine change between the
upgrade of your kernel?  Maybe some gnome-tracker is going off and
indexing all of the data on that device after you mount it, and it
wasn't previously doing that before.  As it is still busy, something has
some open files on that device.

good luck!

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> > > [...]
> > Hi,
> > 
> > > Any chance you can use 'git bisect' to find the offending
> commit?
> > Yes, I am doing it as I managed to build the kernel from source
> 
> Great!  What did you find?

so far, something in between 
2ac5e38ea4203852d6e99edd3cf11f044b0a409f (good) and
b3cc2bfe7244e848f5e8caa77bbdc72c04abd17c (bad)... (about 8 steps left)

> 
> > > And did you accidentally turn on "sync" for the filesystem? 
> > Sorry, I don't think so but actually I don't know exactly what it
> is
> > nor how to check it...
> > 
> > >  How do you
> > > know the old kernel really flushed the buffers out in 1 minute? 
> > 
> > I used to try to unmount the usb media (e.g. "eject" using
> Nautilus
> > file manager), and got a message stating the filesystem was in use
> and
> > could not be mounted, so always answered to not eject it until it
> was
> > unmounted without any warning... does it make sense?
> 
> That does not mean that the data is not flushed to the device yet,
> that
> just means that some userspace program is still accessing the
> device.
> You need to run some other type of test to validate how long it taks
> for
> the data to get to the device.

I understand, I actually omitted here what I found out by using "top",
"ps" and "iotop" to catch the moment when the data write finish. I
found a process named "kworker/u8:0+flush-8:16", or similar, which is
alive while the cp process is in D state (and as long as I can't
"eject" the device), and disappears when the media can be ejected, so
I assumed it to be a good indicator for the data write. But I admit I
am really poorly skilled on this matter, so thanks for pointing it
out, and for any other explanation (or links to deepen it
furthermore).

> 
> > >  But 12
> > > minutes is really long, did anything else change in your
> userspace
> > > between the kernel changes as well?
> > I am not sure if I understand correctly the "userspace" you
> mention:
> > if you mean my home directory and contents, settings etc, then
> yes,
> > maybe... but while I am doing the tests I am quite sure I didn't
> > change anything, and double-checked many times that the 4.20
> kernel is
> > always working (I usually boot up with it when I need to do the
> usual
> > day work).
> 
> I mean, did any other programs on your machine change between the
> upgrade of your kernel?  Maybe some gnome-tracker is going off and
> indexing all of the data on that device after you mount it, and it
> wasn't previously doing that before.  As it is still busy, something
> has
> some open files on that device.

Thank you, now I understand what you mean. Yes, this is definitively
possible (may a "lsof | grep mount_point_of_the_device" or similar
could give some clue?)

Thanks, and bye,
Andrea

Re: Slow I/O on USB media

[Andrea Vai]

[-- Attachment #1: Type: text/plain, Size: 780 bytes --]

Hi,
Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> > > [...]
> > Hi,
> > 
> > > Any chance you can use 'git bisect' to find the offending
> commit?
> > Yes, I am doing it as I managed to build the kernel from source
> 
> Great!  What did you find?

# first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
drm/atomic: Use explicit old crtc state in
drm_atomic_add_affected_planes()

By the way, as I am not expert, is there a way to double-check that I
bisected correctly? (such as, e.g., test with the version before this
one, and then with this commit applied?)

Attached: "git bisect log" output.

Thanks, and bye,
Andrea

[-- Attachment #2: bisectlog.txt --]
[-- Type: text/plain, Size: 3051 bytes --]

git bisect start
# bad: [cd6c84d8f0cdc911df435bb075ba22ce3c605b07] Linux 5.2-rc2
git bisect bad cd6c84d8f0cdc911df435bb075ba22ce3c605b07
# good: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
git bisect good 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
# bad: [d72cb8c7d9dbd9ce820c80f3fddb56b296ba96fc] Merge tag 'riscv-for-linus-5.1-mw0' of git://git.kernel.org/pub/scm/linux/kernel/git/palmer/riscv-linux
git bisect bad d72cb8c7d9dbd9ce820c80f3fddb56b296ba96fc
# bad: [c9bef4a651769927445900564781a9c99fdf6258] Merge tag 'pinctrl-v4.21-1' of git://git.kernel.org/pub/scm/linux/kernel/git/linusw/linux-pinctrl
git bisect bad c9bef4a651769927445900564781a9c99fdf6258
# bad: [e0c38a4d1f196a4b17d2eba36afff8f656a4f1de] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
git bisect bad e0c38a4d1f196a4b17d2eba36afff8f656a4f1de
# bad: [c2f1f3e0e17d94ab0c66d83e669492cb9e9a3698] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/sparc-next
git bisect bad c2f1f3e0e17d94ab0c66d83e669492cb9e9a3698
# bad: [b3cc2bfe7244e848f5e8caa77bbdc72c04abd17c] Merge tag 'i3c/for-4.21' of git://git.kernel.org/pub/scm/linux/kernel/git/i3c/linux
git bisect bad b3cc2bfe7244e848f5e8caa77bbdc72c04abd17c
# good: [2ac5e38ea4203852d6e99edd3cf11f044b0a409f] Merge drm/drm-next into drm-intel-next-queued
git bisect good 2ac5e38ea4203852d6e99edd3cf11f044b0a409f
# bad: [fb878d106b7738ae7cdb513f98876b22bd6a485f] Merge tag 'exynos-drm-next-for-v4.21' of git://git.kernel.org/pub/scm/linux/kernel/git/daeinki/drm-exynos into drm-next
git bisect bad fb878d106b7738ae7cdb513f98876b22bd6a485f
# bad: [818182dd1097fdc492aaef9b08755ea13274352d] Merge tag 'imx-drm-next-2018-12-03' of git://git.pengutronix.de/git/pza/linux into drm-next
git bisect bad 818182dd1097fdc492aaef9b08755ea13274352d
# bad: [ae4ba1936ab97c6a2733a243370f303da3c11839] drm/sun4i: frontend: Determine input mode based on the number of planes
git bisect bad ae4ba1936ab97c6a2733a243370f303da3c11839
# bad: [b39b5394fabc79acbaafb26b777fd348c868bf7e] drm/gem: Add drm_gem_object_funcs
git bisect bad b39b5394fabc79acbaafb26b777fd348c868bf7e
# bad: [7db647aa8b134059c3b8f26b1dd2e1aa5b91e2ca] drm/meson: Add primary plane scaling
git bisect bad 7db647aa8b134059c3b8f26b1dd2e1aa5b91e2ca
# bad: [eb8dd3abeb4dffab6c373e87d09fc3b5858ac158] drm/vc4: Prefer PPF over TPZ when dst >= 2/3 src
git bisect bad eb8dd3abeb4dffab6c373e87d09fc3b5858ac158
# bad: [783195ec1cada862d54dee8f312a60bcbba5c0e4] drm/syncobj: disable the timeline UAPI for now v2
git bisect bad 783195ec1cada862d54dee8f312a60bcbba5c0e4
# bad: [b2432adf33e8c8eb81afaba3030f0ba0145ce7d4] drm/atomic: Use explicit old/new state in drm_atomic_crtc_check()
git bisect bad b2432adf33e8c8eb81afaba3030f0ba0145ce7d4
# bad: [534903d60376b4989b76ec445630aa10f2bc3043] drm/atomic: Use explicit old crtc state in drm_atomic_add_affected_planes()
git bisect bad 534903d60376b4989b76ec445630aa10f2bc3043
# first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043] drm/atomic: Use explicit old crtc state in drm_atomic_add_affected_planes()

Re: Slow I/O on USB media

[Alan Stern]

On Wed, 5 Jun 2019, Andrea Vai wrote:

> Hi,
> Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> > > > [...]
> > > Hi,
> > > 
> > > > Any chance you can use 'git bisect' to find the offending
> > commit?
> > > Yes, I am doing it as I managed to build the kernel from source
> > 
> > Great!  What did you find?
> 
> # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> drm/atomic: Use explicit old crtc state in
> drm_atomic_add_affected_planes()
> 
> By the way, as I am not expert, is there a way to double-check that I
> bisected correctly? (such as, e.g., test with the version before this
> one, and then with this commit applied?)

That is exactly the way to do it: Build a kernel from that commit and 
see that it fails, then revert the commit and see that the resulting 
kernel succeeds.

(Note: The notion of "version before" doesn't have a firm meaning in 
the kernel, because some commits have multiple parents.  The best way 
to see if a single commit caused a change is to do what I said above: 
revert the commit and see what happens.)

Incidentally, it seems very unlikely that a commit for the drm 
subsystem would have any effect on the behavior of a USB storage 
device.

Alan Stern

Re: Slow I/O on USB media

[Andrea Vai]

Hi,
Il giorno mer, 05/06/2019 alle 10.26 -0400, Alan Stern ha scritto:
> On Wed, 5 Jun 2019, Andrea Vai wrote:
> 
> > Hi,
> > Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha
> scritto:
> > > > > [...]
> > > > Hi,
> > > > 
> > > > > Any chance you can use 'git bisect' to find the offending
> > > commit?
> > > > Yes, I am doing it as I managed to build the kernel from
> source
> > > 
> > > Great!  What did you find?
> > 
> > # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> > drm/atomic: Use explicit old crtc state in
> > drm_atomic_add_affected_planes()
> > 
> > By the way, as I am not expert, is there a way to double-check
> that I
> > bisected correctly? (such as, e.g., test with the version before
> this
> > one, and then with this commit applied?)
> 
> That is exactly the way to do it: Build a kernel from that commit
> and 
> see that it fails, then revert the commit and see that the
> resulting 
> kernel succeeds.
> 
> (Note: The notion of "version before" doesn't have a firm meaning
> in 
> the kernel, because some commits have multiple parents.  The best
> way 
> to see if a single commit caused a change is to do what I said
> above: 
> revert the commit and see what happens.)
ok, thank you for pointing it out. So, my question is: how to revert a
commit? (sorry, I prefer to ask you because I am afraid I could do
something wrong, and don't trust too much myself and what I pick up
searching on the web. In the special case, I found "git revert", but
for example how could I revert back a "reversion"? :-/ (I know I miss
the basis, I never worked with git, so sorry for the stupid
question)).

> 
> Incidentally, it seems very unlikely that a commit for the drm 
> subsystem would have any effect on the behavior of a USB storage 
> device.

well, I had the same doubt and that's the reason I was trying to do
the check: I'm afraid I have done something wrong or made a mess with
the bisect process.

Thank you,
Andrea

Re: Slow I/O on USB media

[Alan Stern]

On Wed, 5 Jun 2019, Andrea Vai wrote:

> Hi,
> Il giorno mer, 05/06/2019 alle 10.26 -0400, Alan Stern ha scritto:
> > On Wed, 5 Jun 2019, Andrea Vai wrote:
> > 
> > > Hi,
> > > Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > > > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha
> > scritto:
> > > > > > [...]
> > > > > Hi,
> > > > > 
> > > > > > Any chance you can use 'git bisect' to find the offending
> > > > commit?
> > > > > Yes, I am doing it as I managed to build the kernel from
> > source
> > > > 
> > > > Great!  What did you find?
> > > 
> > > # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> > > drm/atomic: Use explicit old crtc state in
> > > drm_atomic_add_affected_planes()
> > > 
> > > By the way, as I am not expert, is there a way to double-check
> > that I
> > > bisected correctly? (such as, e.g., test with the version before
> > this
> > > one, and then with this commit applied?)
> > 
> > That is exactly the way to do it: Build a kernel from that commit
> > and 
> > see that it fails, then revert the commit and see that the
> > resulting 
> > kernel succeeds.
> > 
> > (Note: The notion of "version before" doesn't have a firm meaning
> > in 
> > the kernel, because some commits have multiple parents.  The best
> > way 
> > to see if a single commit caused a change is to do what I said
> > above: 
> > revert the commit and see what happens.)
> ok, thank you for pointing it out. So, my question is: how to revert a
> commit? (sorry, I prefer to ask you because I am afraid I could do
> something wrong, and don't trust too much myself and what I pick up
> searching on the web. In the special case, I found "git revert", but
> for example how could I revert back a "reversion"? :-/ (I know I miss
> the basis, I never worked with git, so sorry for the stupid
> question)).

In this case it's very simple, since the 534903d60376 commit does have 
a single parent.  You can just do "git checkout 534903d60376^".

More generally, you could do "git show 534903d60376 | git apply -R -".  
That would tell git to write out the commit in the form of a patch and 
then apply the patch in reverse.

Alan Stern

> > Incidentally, it seems very unlikely that a commit for the drm 
> > subsystem would have any effect on the behavior of a USB storage 
> > device.
> 
> well, I had the same doubt and that's the reason I was trying to do
> the check: I'm afraid I have done something wrong or made a mess with
> the bisect process.
> 
> Thank you,
> Andrea

Re: Slow I/O on USB media

[Greg KH]

On Wed, Jun 05, 2019 at 09:36:04AM +0200, Andrea Vai wrote:
> Hi,
> Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha scritto:
> > > > [...]
> > > Hi,
> > > 
> > > > Any chance you can use 'git bisect' to find the offending
> > commit?
> > > Yes, I am doing it as I managed to build the kernel from source
> > 
> > Great!  What did you find?
> 
> # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> drm/atomic: Use explicit old crtc state in
> drm_atomic_add_affected_planes()
> 
> By the way, as I am not expert, is there a way to double-check that I
> bisected correctly? (such as, e.g., test with the version before this
> one, and then with this commit applied?)

How exactly are you "testing" this?

I would recommend a script that does something like:
	mount the disk somewhere
	copy a big file to it
	unmount the disk

testing how long the whole process takes, especially the 'unmount' is
important.  Are you doing that?

Also, you should probably just boot into text mode for this, most
graphical DEs like to auto-mount disks these days.

thanks,

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Hi,
Il giorno mer, 05/06/2019 alle 16.55 +0200, Greg KH ha scritto:
> On Wed, Jun 05, 2019 at 09:36:04AM +0200, Andrea Vai wrote:
> > Hi,
> > Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha
> scritto:
> > > > > [...]
> > > > Hi,
> > > > 
> > > > > Any chance you can use 'git bisect' to find the offending
> > > commit?
> > > > Yes, I am doing it as I managed to build the kernel from
> source
> > > 
> > > Great!  What did you find?
> > 
> > # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> > drm/atomic: Use explicit old crtc state in
> > drm_atomic_add_affected_planes()
> > 
> > By the way, as I am not expert, is there a way to double-check
> that I
> > bisected correctly? (such as, e.g., test with the version before
> this
> > one, and then with this commit applied?)
> 
> How exactly are you "testing" this?
> 
> I would recommend a script that does something like:
>       mount the disk somewhere
>       copy a big file to it
>       unmount the disk
> 
> testing how long the whole process takes, especially the 'unmount'
> is
> important.  Are you doing that?

Well, not exactly, and thank you for pointing me out. I am doing the
job in two ways, from the DE (when I am located at the PC), or in an
ssh session when I am away. In ssh I manually mount the media, then
run

touch begin
date
<cp command>
date
touch end

so I get the time kept looking at the output of "date", or at the date
of the begin/end files. I understand that if I don't unmount the media
I cannot be sure all data has been written, but if the cp command is
still not finished after 20, 30 minutes then I can tag the commit as
"bad". Since I obtained one "good" behavior only (1-2 minutes) among
10+ tests, I took for sure it was a"good" commit, and I may have made
a mistake there (because I am not sure I actually unmounted the
media).

If I use the DE (where the media is mounted automatically) I used to
"eject" the media after the copy finished, and took note of the time
used until the media was correctly "ejected" (and, so, unmounted).

Anyway, I know that I can do all of this in a better way, and will let
you know.

> 
> Also, you should probably just boot into text mode for this, most
> graphical DEs like to auto-mount disks these days.

Thank you for clarifying. As said above, actually I think I have took
care of it, but I can do another bisect by turning off the automount
feature of USB media in my DE, and mount/unmount only by command line.

First of all, I will try to revert the commit, and see what happens.
If the test fails, I will run another bisect.

Thank you for your patience,
Best regards
Andrea

Re: Slow I/O on USB media

[Greg KH]

On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> Hi,
> Il giorno mer, 05/06/2019 alle 16.55 +0200, Greg KH ha scritto:
> > On Wed, Jun 05, 2019 at 09:36:04AM +0200, Andrea Vai wrote:
> > > Hi,
> > > Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha scritto:
> > > > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha
> > scritto:
> > > > > > [...]
> > > > > Hi,
> > > > > 
> > > > > > Any chance you can use 'git bisect' to find the offending
> > > > commit?
> > > > > Yes, I am doing it as I managed to build the kernel from
> > source
> > > > 
> > > > Great!  What did you find?
> > > 
> > > # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> > > drm/atomic: Use explicit old crtc state in
> > > drm_atomic_add_affected_planes()
> > > 
> > > By the way, as I am not expert, is there a way to double-check
> > that I
> > > bisected correctly? (such as, e.g., test with the version before
> > this
> > > one, and then with this commit applied?)
> > 
> > How exactly are you "testing" this?
> > 
> > I would recommend a script that does something like:
> >       mount the disk somewhere
> >       copy a big file to it
> >       unmount the disk
> > 
> > testing how long the whole process takes, especially the 'unmount'
> > is
> > important.  Are you doing that?
> 
> Well, not exactly, and thank you for pointing me out. I am doing the
> job in two ways, from the DE (when I am located at the PC), or in an
> ssh session when I am away. In ssh I manually mount the media, then
> run
> 
> touch begin
> date
> <cp command>
> date
> touch end

That tests nothing other than the size of the memory in your system :(

You have to flush the data out to the device fully in order to properly
measure device throughput.  Calling 'touch' does not do that.

> If I use the DE (where the media is mounted automatically) I used to
> "eject" the media after the copy finished, and took note of the time
> used until the media was correctly "ejected" (and, so, unmounted).

eject/unmount is good.

> Anyway, I know that I can do all of this in a better way, and will let
> you know.

Yes, please do so, your steps above do not show much.

And you need to get your auto-mount out of the way, as who knows what
options your device is being mounted with (i.e. sync or no sync).  You
have to control that yourself in order to be sure.

thanks,

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> [...]
> In ssh I manually mount the media,
> then
> > run
> > 
> > touch begin
> > date
> > <cp command>
> > date
> > touch end
> 
> That tests nothing other than the size of the memory in your system
> :(
> 
> You have to flush the data out to the device fully in order to
> properly
> measure device throughput.  Calling 'touch' does not do that.
> 
> > If I use the DE (where the media is mounted automatically) I used
> to
> > "eject" the media after the copy finished, and took note of the
> time
> > used until the media was correctly "ejected" (and, so, unmounted).
> 
> eject/unmount is good.
> 
> > Anyway, I know that I can do all of this in a better way, and will
> let
> > you know.
> 
> Yes, please do so, your steps above do not show much.

so, just to be sure now, here is my test script:

touch inizio
date
mount UUID="6a9d3c05-6758-49c0-a46e-6ce221478eb3" /mnt/pendrive
cp /NoBackup/buttare/ubuntu-14.04.5-desktop-i386.iso /mnt/pendrive
umount /mnt/pendrive
date
touch fine

can you please confirm (if) it's fine?

> 
> And you need to get your auto-mount out of the way, as who knows
> what
> options your device is being mounted with (i.e. sync or no
> sync).  You
> have to control that yourself in order to be sure.

yes, I disabled the auto-mount. Furthermore, is there any option I
need to specify to the mount command (i.e., as you say, sync or no
sync)?

thanks,
bye
Andrea

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> > Hi,
> > Il giorno mer, 05/06/2019 alle 16.55 +0200, Greg KH ha scritto:
> > > On Wed, Jun 05, 2019 at 09:36:04AM +0200, Andrea Vai wrote:
> > > > Hi,
> > > > Il giorno mar, 04/06/2019 alle 07.43 +0200, Greg KH ha
> scritto:
> > > > > On Mon, Jun 03, 2019 at 01:13:48PM +0200, Andrea Vai wrote:
> > > > > > Il giorno gio, 30/05/2019 alle 06.25 -0700, Greg KH ha
> > > scritto:
> > > > > > > [...]
> > > > > > Hi,
> > > > > > 
> > > > > > > Any chance you can use 'git bisect' to find the
> offending
> > > > > commit?
> > > > > > Yes, I am doing it as I managed to build the kernel from
> > > source
> > > > > 
> > > > > Great!  What did you find?
> > > > 
> > > > # first bad commit: [534903d60376b4989b76ec445630aa10f2bc3043]
> > > > drm/atomic: Use explicit old crtc state in
> > > > drm_atomic_add_affected_planes()
> > > > 
> > > > By the way, as I am not expert, is there a way to double-check
> > > that I
> > > > bisected correctly? (such as, e.g., test with the version
> before
> > > this
> > > > one, and then with this commit applied?)
> > > 
> > > How exactly are you "testing" this?
> > > 
> > > I would recommend a script that does something like:
> > >       mount the disk somewhere
> > >       copy a big file to it
> > >       unmount the disk
> > > 
> > > testing how long the whole process takes, especially the
> 'unmount'
> > > is
> > > important.  Are you doing that?
> > 
> > Well, not exactly, and thank you for pointing me out. I am doing
> the
> > job in two ways, from the DE (when I am located at the PC), or in
> an
> > ssh session when I am away. In ssh I manually mount the media,
> then
> > run
> > 
> > touch begin
> > date
> > <cp command>
> > date
> > touch end
> 
> That tests nothing other than the size of the memory in your system
> :(
> 
> You have to flush the data out to the device fully in order to
> properly
> measure device throughput.  Calling 'touch' does not do that.
> 
> > If I use the DE (where the media is mounted automatically) I used
> to
> > "eject" the media after the copy finished, and took note of the
> time
> > used until the media was correctly "ejected" (and, so, unmounted).
> 
> eject/unmount is good.
> 
> > Anyway, I know that I can do all of this in a better way, and will
> let
> > you know.
> 
> Yes, please do so, your steps above do not show much.
> 
> 

excuse me, another question: since I get the good behavior with kernel
4.20.13 (installed from my distro packages), is it correct to run at
first

git bisect start
git bisect good v4.20.13

, then build the latest kernel, test it, set it as bad (as far as I
can expect) and go on with following tests?

Many thanks,
Andrea

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> [...]
> 
> > Anyway, I know that I can do all of this in a better way, and will
> let
> > you know.
> 
> Yes, please do so, your steps above do not show much.

Here I am with another question.
What I have done so far:

- booted with the last kernel I know to be working (4.20.13-
200.fc29.x86_64, installed from Fedora repos), checked that test runs
fine (2min to copy)
- marked "git bisect good v4.20.13"
- built the latest stable version:
  - git clone https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
  - cp -v /boot/config-$(uname -r) .config
  - make -j4 && make modules_install && make install && grub2-mkconfig -o /boot/grub2/grub.cfg
  - grubby --set-default /boot/vmlinuz-5.2.0-rc3 (the last regular file listed in "ls -lrt /boot/v*")
- rebooted with kernel 5.2.0-rc3, ran the test, took 49min to copy
(!), thus marked "git bisect bad"
- built again, and it turns out to be 4.20.0 (why is it earlier than
4.20.13?), rebooted with 4.20.0, ran the test and it took more than 15
minutes so I killed the cp process, and marked it BAD, and obtained:

The merge base 8fe28cb58bcb235034b64cbbb7550a8a43fd88be is bad.
This means the bug has been fixed between
8fe28cb58bcb235034b64cbbb7550a8a43fd88be and
[0f7c162c1df596e0bba04c26fc9cc497983bf32b].

The output of "git bisect log" is:

git bisect start
# good: [0f7c162c1df596e0bba04c26fc9cc497983bf32b] Linux 4.20.13
git bisect good 0f7c162c1df596e0bba04c26fc9cc497983bf32b
# bad: [f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a] Linux 5.2-rc3
git bisect bad f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a
# bad: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
git bisect bad 8fe28cb58bcb235034b64cbbb7550a8a43fd88be

I can understand that the bug was present before 4.20.13 (is that
reasonable?), but how can I tell bisect to start at 4.20.13, which I
know for sure to be working, and not from 4.20.0, which I actually
don't care about?

I am afraid I am missing something obvious, sorry

Thank you very much,
Andrea

Re: Slow I/O on USB media

[Alan Stern]

On Thu, 6 Jun 2019, Andrea Vai wrote:

> Here I am with another question.
> What I have done so far:
> 
> - booted with the last kernel I know to be working (4.20.13-
> 200.fc29.x86_64, installed from Fedora repos), checked that test runs
> fine (2min to copy)
> - marked "git bisect good v4.20.13"
> - built the latest stable version:
>   - git clone https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
>   - cp -v /boot/config-$(uname -r) .config
>   - make -j4 && make modules_install && make install && grub2-mkconfig -o /boot/grub2/grub.cfg
>   - grubby --set-default /boot/vmlinuz-5.2.0-rc3 (the last regular file listed in "ls -lrt /boot/v*")
> - rebooted with kernel 5.2.0-rc3, ran the test, took 49min to copy
> (!), thus marked "git bisect bad"
> - built again, and it turns out to be 4.20.0 (why is it earlier than
> 4.20.13?), rebooted with 4.20.0, ran the test and it took more than 15
> minutes so I killed the cp process, and marked it BAD, and obtained:
> 
> The merge base 8fe28cb58bcb235034b64cbbb7550a8a43fd88be is bad.
> This means the bug has been fixed between
> 8fe28cb58bcb235034b64cbbb7550a8a43fd88be and
> [0f7c162c1df596e0bba04c26fc9cc497983bf32b].
> 
> The output of "git bisect log" is:
> 
> git bisect start
> # good: [0f7c162c1df596e0bba04c26fc9cc497983bf32b] Linux 4.20.13
> git bisect good 0f7c162c1df596e0bba04c26fc9cc497983bf32b
> # bad: [f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a] Linux 5.2-rc3
> git bisect bad f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a
> # bad: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
> git bisect bad 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
> 
> I can understand that the bug was present before 4.20.13 (is that
> reasonable?), but how can I tell bisect to start at 4.20.13, which I
> know for sure to be working, and not from 4.20.0, which I actually
> don't care about?

So what you got was a meaningless result.  Bisection works by assuming 
assuming that it's looking for a commit that introduced a problem.  If 
the earliest commit you test already has the problem (and 4.20.0 is 
earlier than 4.20.13) then bisection won't do anything.

In your case it looks like something added between 4.20.0 and 4.20.13 
caused the problem to go away!  You can still use bisection to find the 
commit which did that, but the idea is a little unintuitive.

Start out by telling git that 4.20.0 is "good" and 4.20.13 is "bad".  
Then test the intermediate commits as you have been doing, and say that 
the commit is "good" if the copy takes a long time and "bad" if the 
copy takes a short time.  That should help to find the first commit 
which caused the problem to go away.  (Assuming that the problem is 
caused by the kernel and not by something else...)

Alan Stern

Re: Slow I/O on USB media

[Greg KH]

On Thu, Jun 06, 2019 at 04:00:52PM +0200, Andrea Vai wrote:
> Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> > On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> > [...]
> > 
> > > Anyway, I know that I can do all of this in a better way, and will
> > let
> > > you know.
> > 
> > Yes, please do so, your steps above do not show much.
> 
> Here I am with another question.
> What I have done so far:
> 
> - booted with the last kernel I know to be working (4.20.13-
> 200.fc29.x86_64, installed from Fedora repos), checked that test runs

We have no idea what is in a random distro kernel, sorry.

So I would start with a kernel.org kernel.  That keeps things at an even
level, and you are using a "known good" configuration as well.

> fine (2min to copy)
> - marked "git bisect good v4.20.13"
> - built the latest stable version:
>   - git clone https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
>   - cp -v /boot/config-$(uname -r) .config
>   - make -j4 && make modules_install && make install && grub2-mkconfig -o /boot/grub2/grub.cfg
>   - grubby --set-default /boot/vmlinuz-5.2.0-rc3 (the last regular file listed in "ls -lrt /boot/v*")
> - rebooted with kernel 5.2.0-rc3, ran the test, took 49min to copy
> (!), thus marked "git bisect bad"
> - built again, and it turns out to be 4.20.0 (why is it earlier than
> 4.20.13?), rebooted with 4.20.0, ran the test and it took more than 15
> minutes so I killed the cp process, and marked it BAD, and obtained:
> 
> The merge base 8fe28cb58bcb235034b64cbbb7550a8a43fd88be is bad.
> This means the bug has been fixed between
> 8fe28cb58bcb235034b64cbbb7550a8a43fd88be and
> [0f7c162c1df596e0bba04c26fc9cc497983bf32b].
> 
> The output of "git bisect log" is:
> 
> git bisect start
> # good: [0f7c162c1df596e0bba04c26fc9cc497983bf32b] Linux 4.20.13
> git bisect good 0f7c162c1df596e0bba04c26fc9cc497983bf32b
> # bad: [f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a] Linux 5.2-rc3
> git bisect bad f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a
> # bad: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
> git bisect bad 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
> 
> I can understand that the bug was present before 4.20.13 (is that
> reasonable?), but how can I tell bisect to start at 4.20.13, which I
> know for sure to be working, and not from 4.20.0, which I actually
> don't care about?
> 
> I am afraid I am missing something obvious, sorry

As Alan said, 4.20 is older than 4.20.13.

But, is the kernel.org version of 4.20.13 really "good" here?

I would start with Linus's tree and stay away from the stable trees
for now.  As you end up with odd "leafs" that can confuse 'git bisect'
and everyone else.

So start with 4.20.0.  Test that.  If it is "good", then great!

If not, then maybe you are not really using the same kernel
configuration that Fedora is, _or_ Fedora has some odd kernel patch
added that makes things an order of magnitude faster :)

thanks,

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno gio, 06/06/2019 alle 16.47 +0200, Greg KH ha scritto:
> 
> 
> [...]
> 
> As Alan said, 4.20 is older than 4.20.13.

Thank you Greg, and thank you Alan for your explanations.

> 
> But, is the kernel.org version of 4.20.13 really "good" here?
> 
> I would start with Linus's tree and stay away from the stable trees
> for now.

ok, so hope I have understood correctly and started a new bisect from

git clone git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git

, built it, tested it (5.2.0-rc3+) and marked as "bad",

>   As you end up with odd "leafs" that can confuse 'git bisect'
> and everyone else.
> 
> So start with 4.20.0.  

and I hope have understood correctly and did

wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/snapshot/linux-4.20.tar.gz

and built it and tested it,

> Test that.  If it is "good", then great!

...and ok is good :-), so issued

git bisect good v4.20

...and I am going on there. So far:

$ git bisect log
git bisect start
# good: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
git bisect good 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
# bad: [01047631df813f6247185547c3778c80af088a20] Merge tag 'xfs-5.2-fixes-2' of git://git.kernel.org/pub/scm/fs/xfs/xfs-linux
git bisect bad 01047631df813f6247185547c3778c80af088a20
# bad: [bcd49c3dd172c38e14faf151adca63c8db4c9557] Merge branch 'x86-cleanups-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad bcd49c3dd172c38e14faf151adca63c8db4c9557
# bad: [fcf010449ebe1db0cb68b2c6410972a782f2bd14] Merge tag 'kgdb-4.21-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/danielt/linux
git bisect bad fcf010449ebe1db0cb68b2c6410972a782f2bd14

Please correct if I am missing something, or doing something different
from what you meant.

Thank you!
Andrea

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno gio 6 giu 2019 alle ore 16:48 Greg KH
<gregkh@linuxfoundation.org> ha scritto:
>
> On Thu, Jun 06, 2019 at 04:00:52PM +0200, Andrea Vai wrote:
> > Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> > > On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> > > [...]
> > >
> > > > Anyway, I know that I can do all of this in a better way, and will
> > > let
> > > > you know.
> > >
> > > Yes, please do so, your steps above do not show much.
> >
> > Here I am with another question.
> > What I have done so far:
> >
> > - booted with the last kernel I know to be working (4.20.13-
> > 200.fc29.x86_64, installed from Fedora repos), checked that test runs
>
> We have no idea what is in a random distro kernel, sorry.
>
> So I would start with a kernel.org kernel.  That keeps things at an even
> level, and you are using a "known good" configuration as well.
>
> > fine (2min to copy)
> > - marked "git bisect good v4.20.13"
> > - built the latest stable version:
> >   - git clone https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
> >   - cp -v /boot/config-$(uname -r) .config
> >   - make -j4 && make modules_install && make install && grub2-mkconfig -o /boot/grub2/grub.cfg
> >   - grubby --set-default /boot/vmlinuz-5.2.0-rc3 (the last regular file listed in "ls -lrt /boot/v*")
> > - rebooted with kernel 5.2.0-rc3, ran the test, took 49min to copy
> > (!), thus marked "git bisect bad"
> > - built again, and it turns out to be 4.20.0 (why is it earlier than
> > 4.20.13?), rebooted with 4.20.0, ran the test and it took more than 15
> > minutes so I killed the cp process, and marked it BAD, and obtained:
> >
> > The merge base 8fe28cb58bcb235034b64cbbb7550a8a43fd88be is bad.
> > This means the bug has been fixed between
> > 8fe28cb58bcb235034b64cbbb7550a8a43fd88be and
> > [0f7c162c1df596e0bba04c26fc9cc497983bf32b].
> >
> > The output of "git bisect log" is:
> >
> > git bisect start
> > # good: [0f7c162c1df596e0bba04c26fc9cc497983bf32b] Linux 4.20.13
> > git bisect good 0f7c162c1df596e0bba04c26fc9cc497983bf32b
> > # bad: [f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a] Linux 5.2-rc3
> > git bisect bad f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a
> > # bad: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
> > git bisect bad 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
> >
> > I can understand that the bug was present before 4.20.13 (is that
> > reasonable?), but how can I tell bisect to start at 4.20.13, which I
> > know for sure to be working, and not from 4.20.0, which I actually
> > don't care about?
> >
> > I am afraid I am missing something obvious, sorry
>
> As Alan said, 4.20 is older than 4.20.13.
>
> But, is the kernel.org version of 4.20.13 really "good" here?
>
> I would start with Linus's tree and stay away from the stable trees
> for now.  As you end up with odd "leafs" that can confuse 'git bisect'
> and everyone else.
>
> So start with 4.20.0.  Test that.  If it is "good", then great!

Hi,
  there is also something else I don't understand.
Every time I build a kernel, then after booting it "uname -a" shows
something like

Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019 x86_64
x86_64 x86_64 GNU/Linux

where the number after "#" increments by 1 from the previous build.

Now I have the same number (#12) after a new build, is it normal?
Furthermore, "ls -lrt /boot/v*" shows the last lines to be

-rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-4.19.0-rc5+.old
-rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-4.19.0-rc5+

and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-rc5+"
shows they are identical. Why? I expected that each bisect would lead
to a different kernel.
Assuming that the opposite can happen, does it mean that when I say
i.e. "git bisect bad", then build a new kernel and see that is
identical to the previous one I can run "git bisect bad" without
booting into the new one and even making the test?

Another thing I don't understand is that I told 4.20.0 to be good, so
I would expect that I don't need to test any older version, but as far
as I know 4.19.0-rc5+ is older than 4.20.0, so why is it involved in
the bisection?

I had to "git bisect skip" one time (the kernel did not boot), but as
far as I know I don't think this could be related to my doubts.

Current output of "git bisect log" is

git bisect start
# good: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
git bisect good 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
# bad: [01047631df813f6247185547c3778c80af088a20] Merge tag
'xfs-5.2-fixes-2' of git://git.kernel.org/pub/scm/fs/xfs/xfs-linux
git bisect bad 01047631df813f6247185547c3778c80af088a20
# bad: [bcd49c3dd172c38e14faf151adca63c8db4c9557] Merge branch
'x86-cleanups-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad bcd49c3dd172c38e14faf151adca63c8db4c9557
# bad: [fcf010449ebe1db0cb68b2c6410972a782f2bd14] Merge tag
'kgdb-4.21-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/danielt/linux
git bisect bad fcf010449ebe1db0cb68b2c6410972a782f2bd14
# bad: [e0c38a4d1f196a4b17d2eba36afff8f656a4f1de] Merge
git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
git bisect bad e0c38a4d1f196a4b17d2eba36afff8f656a4f1de
# bad: [c2f1f3e0e17d94ab0c66d83e669492cb9e9a3698] Merge
git://git.kernel.org/pub/scm/linux/kernel/git/davem/sparc-next
git bisect bad c2f1f3e0e17d94ab0c66d83e669492cb9e9a3698
# bad: [b3cc2bfe7244e848f5e8caa77bbdc72c04abd17c] Merge tag
'i3c/for-4.21' of
git://git.kernel.org/pub/scm/linux/kernel/git/i3c/linux
git bisect bad b3cc2bfe7244e848f5e8caa77bbdc72c04abd17c
# bad: [2ac5e38ea4203852d6e99edd3cf11f044b0a409f] Merge drm/drm-next
into drm-intel-next-queued
git bisect bad 2ac5e38ea4203852d6e99edd3cf11f044b0a409f
# skip: [63ac3328f0d1d37f286e397b14d9596ed09d7ca5] drm/i915: fix
broadwell EU computation
git bisect skip 63ac3328f0d1d37f286e397b14d9596ed09d7ca5
# bad: [ca05359f1e64cf8303ee532e50efe4ab7563d4a9] dma-buf: allow
reserving more than one shared fence slot
git bisect bad ca05359f1e64cf8303ee532e50efe4ab7563d4a9
# bad: [21ebe615c16994f340fe2b6735aad31fd1d0014c] drm: Remove
transitional helpers
git bisect bad 21ebe615c16994f340fe2b6735aad31fd1d0014c
# bad: [a0d4d42cb5854400baa47bf63d9aae65fa9f484e] drm/bochs: Replace
drm_gem_object_unreference_unlocked with put function
git bisect bad a0d4d42cb5854400baa47bf63d9aae65fa9f484e

Many thanks,
Andrea

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno sab 8 giu 2019 alle ore 09:43 Andrea Vai
<andrea.vai@unipv.it> ha scritto:
>
>[...]
>
> Hi,
>   there is also something else I don't understand.
> Every time I build a kernel, then after booting it "uname -a" shows
> something like
>
> Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019 x86_64
> x86_64 x86_64 GNU/Linux
>
> where the number after "#" increments by 1 from the previous build.
>
> Now I have the same number (#12) after a new build, is it normal?
> Furthermore, "ls -lrt /boot/v*" shows the last lines to be
>
> -rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-4.19.0-rc5+.old
> -rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-4.19.0-rc5+
>
> and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-rc5+"
> shows they are identical. Why? I expected that each bisect would lead
> to a different kernel.
> Assuming that the opposite can happen, does it mean that when I say
> i.e. "git bisect bad", then build a new kernel and see that is
> identical to the previous one I can run "git bisect bad" without
> booting into the new one and even making the test?
>
> Another thing I don't understand is that I told 4.20.0 to be good, so
> I would expect that I don't need to test any older version, but as far
> as I know 4.19.0-rc5+ is older than 4.20.0, so why is it involved in
> the bisection?
>
> I had to "git bisect skip" one time (the kernel did not boot), but as
> far as I know I don't think this could be related to my doubts.
> [...]

Update:
  I have concluded the bisection, found that
"9cb5f4873b993497d462b9406f9a1d8a148e461b is the first bad commit",
reverted it, and the test still fails (btw, the final kernel file,
/boot/vmlinuz-4.19.0-rc5+, does not differ from the previous one).

So, all my doubts above are still there (and growing). What I am doing wrong?

Thank you,
Andrea

Re: Slow I/O on USB media

[Greg KH]

On Sat, Jun 08, 2019 at 11:29:16AM +0200, Andrea Vai wrote:
> Il giorno sab 8 giu 2019 alle ore 09:43 Andrea Vai
> <andrea.vai@unipv.it> ha scritto:
> >
> >[...]
> >
> > Hi,
> >   there is also something else I don't understand.
> > Every time I build a kernel, then after booting it "uname -a" shows
> > something like
> >
> > Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019 x86_64
> > x86_64 x86_64 GNU/Linux
> >
> > where the number after "#" increments by 1 from the previous build.
> >
> > Now I have the same number (#12) after a new build, is it normal?
> > Furthermore, "ls -lrt /boot/v*" shows the last lines to be
> >
> > -rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-4.19.0-rc5+.old
> > -rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-4.19.0-rc5+
> >
> > and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-rc5+"
> > shows they are identical. Why? I expected that each bisect would lead
> > to a different kernel.
> > Assuming that the opposite can happen, does it mean that when I say
> > i.e. "git bisect bad", then build a new kernel and see that is
> > identical to the previous one I can run "git bisect bad" without
> > booting into the new one and even making the test?
> >
> > Another thing I don't understand is that I told 4.20.0 to be good, so
> > I would expect that I don't need to test any older version, but as far
> > as I know 4.19.0-rc5+ is older than 4.20.0, so why is it involved in
> > the bisection?
> >
> > I had to "git bisect skip" one time (the kernel did not boot), but as
> > far as I know I don't think this could be related to my doubts.
> > [...]
> 
> Update:
>   I have concluded the bisection, found that
> "9cb5f4873b993497d462b9406f9a1d8a148e461b is the first bad commit",
> reverted it, and the test still fails (btw, the final kernel file,
> /boot/vmlinuz-4.19.0-rc5+, does not differ from the previous one).
> 
> So, all my doubts above are still there (and growing). What I am doing wrong?

Are you _SURE_ that a 4.20.0 release actually worked properly for you?
Did you build one and do your tests?  Or are you just relying on your
Fedora build still?

that's all I can think of here, sorry.

greg k-h

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno lun, 10/06/2019 alle 16.38 +0200, Greg KH ha scritto:
> On Sat, Jun 08, 2019 at 11:29:16AM +0200, Andrea Vai wrote:
> > Il giorno sab 8 giu 2019 alle ore 09:43 Andrea Vai
> > <andrea.vai@unipv.it> ha scritto:
> > >
> > >[...]
> > >
> > > Hi,
> > >   there is also something else I don't understand.
> > > Every time I build a kernel, then after booting it "uname -a"
> shows
> > > something like
> > >
> > > Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019
> x86_64
> > > x86_64 x86_64 GNU/Linux
> > >
> > > where the number after "#" increments by 1 from the previous
> build.
> > >
> > > Now I have the same number (#12) after a new build, is it
> normal?
> > > Furthermore, "ls -lrt /boot/v*" shows the last lines to be
> > >
> > > -rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-
> 4.19.0-rc5+.old
> > > -rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-
> 4.19.0-rc5+
> > >
> > > and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-
> rc5+"
> > > shows they are identical. Why? I expected that each bisect would
> lead
> > > to a different kernel.
> > > Assuming that the opposite can happen, does it mean that when I
> say
> > > i.e. "git bisect bad", then build a new kernel and see that is
> > > identical to the previous one I can run "git bisect bad" without
> > > booting into the new one and even making the test?
> > >
> > > Another thing I don't understand is that I told 4.20.0 to be
> good, so
> > > I would expect that I don't need to test any older version, but
> as far
> > > as I know 4.19.0-rc5+ is older than 4.20.0, so why is it
> involved in
> > > the bisection?
> > >
> > > I had to "git bisect skip" one time (the kernel did not boot),
> but as
> > > far as I know I don't think this could be related to my doubts.
> > > [...]
> > 
> > Update:
> >   I have concluded the bisection, found that
> > "9cb5f4873b993497d462b9406f9a1d8a148e461b is the first bad
> commit",
> > reverted it, and the test still fails (btw, the final kernel file,
> > /boot/vmlinuz-4.19.0-rc5+, does not differ from the previous one).
> > 
> > So, all my doubts above are still there (and growing). What I am
> doing wrong?
> 
> Are you _SURE_ that a 4.20.0 release actually worked properly for
> you?
> Did you build one and do your tests?  Or are you just relying on
> your
> Fedora build still?

Yes, I am really sure of that, and the definitive proof is that since
I stopped bisecting I made the 4.20.0 the default boot kernel, and all
my backups are done "quickly" (12min to create a 12GB archive).
Furthermore, "uname -a" shows

Linux 4.20.0 #1 SMP Thu Jun 6 22:32:29 CEST 2019 x86_64 x86_64 x86_64
GNU/Linux

To have one more evidence, I started the test while writing down this
sentence, and it has just finished in one minute and a half (1 GB file
copy).

I will go on following your other suggestions; by the time, thank you
for pointing this out,

Andrea

Re: Slow I/O on USB media

[Alan Stern]

On Sat, 8 Jun 2019, Andrea Vai wrote:

> Il giorno sab 8 giu 2019 alle ore 09:43 Andrea Vai
> <andrea.vai@unipv.it> ha scritto:
> >
> >[...]
> >
> > Hi,
> >   there is also something else I don't understand.
> > Every time I build a kernel, then after booting it "uname -a" shows
> > something like
> >
> > Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019 x86_64
> > x86_64 x86_64 GNU/Linux
> >
> > where the number after "#" increments by 1 from the previous build.
> >
> > Now I have the same number (#12) after a new build, is it normal?

That number is set up by the kernel's build system, and it is 
automatically incremented each time you build a kernel (look for a file 
named ".version" in the top-level kernel source directory).  It should 
be different each time.

> > Furthermore, "ls -lrt /boot/v*" shows the last lines to be
> >
> > -rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-4.19.0-rc5+.old
> > -rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-4.19.0-rc5+
> >
> > and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-rc5+"
> > shows they are identical. Why? I expected that each bisect would lead
> > to a different kernel.

Maybe you aren't building or installing the kernels correctly.

> > Assuming that the opposite can happen, does it mean that when I say
> > i.e. "git bisect bad", then build a new kernel and see that is
> > identical to the previous one I can run "git bisect bad" without
> > booting into the new one and even making the test?

Yes, except that the new kernel should never be identical to the old 
one.

> > Another thing I don't understand is that I told 4.20.0 to be good, so
> > I would expect that I don't need to test any older version, but as far
> > as I know 4.19.0-rc5+ is older than 4.20.0, so why is it involved in
> > the bisection?

I don't know.

> > I had to "git bisect skip" one time (the kernel did not boot), but as
> > far as I know I don't think this could be related to my doubts.
> > [...]
> 
> Update:
>   I have concluded the bisection, found that
> "9cb5f4873b993497d462b9406f9a1d8a148e461b is the first bad commit",
> reverted it, and the test still fails (btw, the final kernel file,
> /boot/vmlinuz-4.19.0-rc5+, does not differ from the previous one).

It sounds like you did not do the bisection or testing correctly.

> So, all my doubts above are still there (and growing). What I am doing wrong?

Without knowing exactly what you are doing, it's impossible to say what 
you're doing wrong.  Some possibilities include:

	Not setting up the .config file properly for each build.

	Not installing the new kernel in the right place.

	Booting some kernel other than the new one when you test.

Sometimes doing "make clean" before each build will help.

Also, it's possible that what you're testing for isn't caused by the 
kernel in the first place (i.e., running the test several times under 
the _same_ kernel might give different results).  In that case, 
bisection would be pointless.

Alan Stern

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno lun, 10/06/2019 alle 10.40 -0400, Alan Stern ha scritto:
> 
> 
> [...]

Thank you Alan and Greg for your patience and answer. I will carefully
consider all the advice you gave me, but one in particular stands out
to me first:

>         Not setting up the .config file properly for each build.

How should I set up the .config file properly for each build? What I
did so far was

cp -v /boot/config-$(uname -r) .config

(when I was using a "working kernel", maybe the Fedora one) before the
first build, then never touched the .config dir again during the
bisection.

(Also, I use to press ENTER to accept all default choices when
compiling, is that correct?)

Many thanks,
Andrea Vai

Re: Slow I/O on USB media

[Alan Stern]

On Mon, 10 Jun 2019, Andrea Vai wrote:

> Il giorno lun, 10/06/2019 alle 10.40 -0400, Alan Stern ha scritto:
> > 
> > 
> > [...]
> 
> Thank you Alan and Greg for your patience and answer. I will carefully
> consider all the advice you gave me, but one in particular stands out
> to me first:
> 
> >         Not setting up the .config file properly for each build.
> 
> How should I set up the .config file properly for each build? What I
> did so far was
> 
> cp -v /boot/config-$(uname -r) .config
> 
> (when I was using a "working kernel", maybe the Fedora one) before the
> first build, then never touched the .config dir again during the
> bisection.

In theory, the best approach is to always start from a single, fixed 
configuration, such as the one your Fedora kernel came with.  In 
practice it may not matter very much.

> (Also, I use to press ENTER to accept all default choices when
> compiling, is that correct?)

As long as the resulting kernel runs okay and includes the drivers you 
need, it's okay.  Just try to minimize the differences among the 
various kernels you build.

Alan Stern

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno lun, 10/06/2019 alle 10.40 -0400, Alan Stern ha scritto:
> On Sat, 8 Jun 2019, Andrea Vai wrote:
> 
> [...]

Hi,
  I have concluded the (third) bisect, and still haven't come to an
end, but I have collected as much information as I can:

- I started again from:
cd /NoBackup/kernel
rm -rf linux
git clone git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
cd linux
cp /boot/config-4.20.13-200.fc29.x86_64 .config
git bisect start
git bisect good v4.20

- To build each kernel, I have created a build script that simply
does:
make clean && make -j4 && make modules_install && make install &&
grub2-mkconfig -o /boot/grub2/grub.cfg && ls -lrt /boot/v*

- Then, used grubby --set-default to set the last kernel built (took
from the output of the last command of the build script)

- Rebooted and check with "uname -a" that the correct kernel is
actually the last built, comparing the # in the output of "uname -a"
with the content of the .version file;

- Do the test, using a script I created:

logfile=...
echo -n "Inizio: " | tee -a $logfile
date | tee -a $logfile
uname -a | tee -a $logfile
touch inizio
mount UUID="05141239-4ea5-494d-aa91-acd67db89ce5" /mnt/pendrive
cp /NoBackup/buttare/ubuntu-14.04.5-desktop-i386.iso /mnt/pendrive
umount /mnt/pendrive
echo -n "...fine: " | tee -a $logfile
date | tee -a $logfile
touch fine

Then, from the script output and the log file, I ran "git bisect bad"
each time the time taken was more than the time resulting with the
"good" kernel(s) (then started again with the build, and so on).

That happened ALL times, so I never encountered a kernel that made me
say "git bisect good". Usually, the time took more than 20 minutes
(remember, the good kernel takes 1min15sec to copy), except a couple
of cases where it took 11 and 15 minutes. I assumed that a "good"
kernel would be one that behaves the same as the "original good" one
(1:15 min), but may I be wrong in this assumption? Note that the
1:15min time is measured when the system usually makes (lot of) other
work, because it's the kernel I use regularly (i.e., also when I don't
do the tests).

Also, to answer to Alan:

   Also, it's possible that what you're testing for isn't caused by
   the 
   kernel in the first place (i.e., running the test several times
   under 
   the _same_ kernel might give different results).  In that case, 
   bisection would be pointless.

I have tried to exclude it by doing many tries (10) for some kernels.
I should have done it for all the kernels I built, but for now I did
it for the last one (see below) and "good" one (4.20) only, because I
would like to be sure the good one really runs fine, and in this case
the results are very homogeneous: average time is 1:12 (m:s), and the
standard deviation is 3 seconds.

For the other kernels I did one only try each, and they give very
different results among each other, spacing from 55min to 6min (other
examples are 38, 11, 22, 28, 23, 25, 15, 22, 30, 13 min), but even
with the best case the result was some 5 times slower than the "good"
one, so I marked it as "bad".

The ".config" file was never touched by me manually (I noticed that
sometimes I had to reply to some questions to configure the kernel,
and in those cases the .config content changed. Those cases were
frequent at the beginning of the bisect, and never happened after the
7th, 8th step roughly).

The last bisect command showed:

a1cccdcf330e2a59b72b1588a7ef87cbaaa8a4e9 is the first bad commit
commit a1cccdcf330e2a59b72b1588a7ef87cbaaa8a4e9
Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
Date:   Thu Sep 20 12:27:04 2018 +0200

    drm/i915: Clean up casts to crtc_state in
intel_atomic_commit_tail()
    
    Use old/new_intel_crtc_state, and get rid of all the conversion
casts
    where they don't add anything.
    
    Signed-off-by: Maarten Lankhorst <
maarten.lankhorst@linux.intel.com>
    Reviewed-by: Matt Roper <matthew.d.roper@intel.com>
    Link: 
https://patchwork.freedesktop.org/patch/msgid/20180920102711.4184-2-maarten.lankhorst@linux.intel.com


And reverting it may have helped "a little", but didn't make the
problem disappear: 10 tries gave 4:47 +/- 2:01 minutes (but note that
I didn't do the 10 trials for the preceding kernel, and the only trial
on it gave 6:25 min).

By the way, I noticed an error ("Unexpected system error") reported
sometimes by the Fedora ABRT tool, that states "this is not a software
bug, the kernel log indicates it is a hardware error", or something
similar (sorry, at the moment I don't know exactly where to find it).

I have described as accurately 	as possible the steps I took because I
hope that you can find some mistakes in them. Sorry if it turns out to
be boring.

What do you suggest me?

Many thanks in advance for your help,
Andrea Vai

Re: Slow I/O on USB media

[Alan Stern]

On Mon, 17 Jun 2019, Andrea Vai wrote:

> Il giorno lun, 10/06/2019 alle 10.40 -0400, Alan Stern ha scritto:
> > On Sat, 8 Jun 2019, Andrea Vai wrote:
> > 
> > [...]
> 
> Hi,
>   I have concluded the (third) bisect, and still haven't come to an
> end, but I have collected as much information as I can:
> 
> - I started again from:
> cd /NoBackup/kernel
> rm -rf linux
> git clone git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
> cd linux
> cp /boot/config-4.20.13-200.fc29.x86_64 .config
> git bisect start
> git bisect good v4.20
> 
> - To build each kernel, I have created a build script that simply
> does:
> make clean && make -j4 && make modules_install && make install &&
> grub2-mkconfig -o /boot/grub2/grub.cfg && ls -lrt /boot/v*
> 
> - Then, used grubby --set-default to set the last kernel built (took
> from the output of the last command of the build script)
> 
> - Rebooted and check with "uname -a" that the correct kernel is
> actually the last built, comparing the # in the output of "uname -a"
> with the content of the .version file;
> 
> - Do the test, using a script I created:
> 
> logfile=...
> echo -n "Inizio: " | tee -a $logfile
> date | tee -a $logfile
> uname -a | tee -a $logfile
> touch inizio
> mount UUID="05141239-4ea5-494d-aa91-acd67db89ce5" /mnt/pendrive
> cp /NoBackup/buttare/ubuntu-14.04.5-desktop-i386.iso /mnt/pendrive
> umount /mnt/pendrive
> echo -n "...fine: " | tee -a $logfile
> date | tee -a $logfile
> touch fine
> 
> Then, from the script output and the log file, I ran "git bisect bad"
> each time the time taken was more than the time resulting with the
> "good" kernel(s) (then started again with the build, and so on).
> 
> That happened ALL times, so I never encountered a kernel that made me
> say "git bisect good".

Really?  That strongly suggests that the 4.20 kernel also should have
been marked bad.  Did you really test it exactly the same way as all
the others?  That is, did you go through the entire procedure starting
with "git checkout v4.20", then running the build script, then the
reboot and "uname -a", and then the test script?

Or did you just run a few tests with the Fedora 4.20.13 kernel and
assume that the results would be the same as those?

> Usually, the time took more than 20 minutes
> (remember, the good kernel takes 1min15sec to copy), except a couple
> of cases where it took 11 and 15 minutes. I assumed that a "good"
> kernel would be one that behaves the same as the "original good" one
> (1:15 min), but may I be wrong in this assumption? Note that the
> 1:15min time is measured when the system usually makes (lot of) other
> work, because it's the kernel I use regularly (i.e., also when I don't
> do the tests).
> 
> Also, to answer to Alan:
> 
>    Also, it's possible that what you're testing for isn't caused by
>    the 
>    kernel in the first place (i.e., running the test several times
>    under 
>    the _same_ kernel might give different results).  In that case, 
>    bisection would be pointless.
> 
> I have tried to exclude it by doing many tries (10) for some kernels.
> I should have done it for all the kernels I built, but for now I did
> it for the last one (see below) and "good" one (4.20) only, because I
> would like to be sure the good one really runs fine, and in this case
> the results are very homogeneous: average time is 1:12 (m:s), and the
> standard deviation is 3 seconds.
> 
> For the other kernels I did one only try each, and they give very
> different results among each other, spacing from 55min to 6min (other
> examples are 38, 11, 22, 28, 23, 25, 15, 22, 30, 13 min), but even
> with the best case the result was some 5 times slower than the "good"
> one, so I marked it as "bad".
> 
> The ".config" file was never touched by me manually (I noticed that
> sometimes I had to reply to some questions to configure the kernel,
> and in those cases the .config content changed. Those cases were
> frequent at the beginning of the bisect, and never happened after the
> 7th, 8th step roughly).
> 
> The last bisect command showed:
> 
> a1cccdcf330e2a59b72b1588a7ef87cbaaa8a4e9 is the first bad commit
> commit a1cccdcf330e2a59b72b1588a7ef87cbaaa8a4e9
> Author: Maarten Lankhorst <maarten.lankhorst@linux.intel.com>
> Date:   Thu Sep 20 12:27:04 2018 +0200
> 
>     drm/i915: Clean up casts to crtc_state in
> intel_atomic_commit_tail()
>     
>     Use old/new_intel_crtc_state, and get rid of all the conversion
> casts
>     where they don't add anything.
>     
>     Signed-off-by: Maarten Lankhorst <
> maarten.lankhorst@linux.intel.com>
>     Reviewed-by: Matt Roper <matthew.d.roper@intel.com>
>     Link: 
> https://patchwork.freedesktop.org/patch/msgid/20180920102711.4184-2-maarten.lankhorst@linux.intel.com
> 
> 
> And reverting it may have helped "a little", but didn't make the
> problem disappear: 10 tries gave 4:47 +/- 2:01 minutes (but note that
> I didn't do the 10 trials for the preceding kernel, and the only trial
> on it gave 6:25 min).

If _all_ the kernels you built and tested were bad then you probably 
did not start the bisection from the right commit.

> By the way, I noticed an error ("Unexpected system error") reported
> sometimes by the Fedora ABRT tool, that states "this is not a software
> bug, the kernel log indicates it is a hardware error", or something
> similar (sorry, at the moment I don't know exactly where to find it).

Did you look in the kernel log?

> I have described as accurately 	as possible the steps I took because I
> hope that you can find some mistakes in them. Sorry if it turns out to
> be boring.
> 
> What do you suggest me?

Compare the mainstream 4.20 kernel with the Fedora 4.20.13 kernel.  
Also, maybe compare the mainstream 4.20.13 with Fedora's 4.20.13.

Alan Stern

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno lun, 17/06/2019 alle 12.14 -0400, Alan Stern ha scritto:
> On Mon, 17 Jun 2019, Andrea Vai wrote:
> 
> > [...]
> > 
> > That happened ALL times, so I never encountered a kernel that made
> me
> > say "git bisect good".
> 
> Really?  That strongly suggests that the 4.20 kernel also should
> have
> been marked bad.  Did you really test it exactly the same way as all
> the others?  That is, did you go through the entire procedure
> starting
> with "git checkout v4.20", then running the build script, then the
> reboot and "uname -a", and then the test script?

well, honestly, no, because (sigh) I didn't know the "git checkout"
command, sorry. I started with building 4.20 from the source
downloaded with

 wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/snapshot/linux-4.20.tar.gz

, then said "git bisect good v4.20".

Is this different from "git checkout v4.20"? I hope it is, so we have
found the mistake I have done.


> Or did you just run a few tests with the Fedora 4.20.13 kernel and
> assume that the results would be the same as those?

no, I am sure I have never used the Fedora kernel(s) during the last
bisect process.

> 
> > [...]
> 
> If _all_ the kernels you built and tested were bad then you
> probably 
> did not start the bisection from the right commit.

so, I hope this is true :-)

> 
> > By the way, I noticed an error ("Unexpected system error")
> reported
> > sometimes by the Fedora ABRT tool, that states "this is not a
> software
> > bug, the kernel log indicates it is a hardware error", or
> something
> > similar (sorry, at the moment I don't know exactly where to find
> it).
> 
> Did you look in the kernel log?

Yes I did, but I didn't took care about it very much. I will do it
again, and report here, if as far as I understand you are saying that
it could be useful.

> 
> > [...]
> 
> Compare the mainstream 4.20 kernel with the Fedora 4.20.13 kernel.  
> Also, maybe compare the mainstream 4.20.13 with Fedora's 4.20.13.

Sorry, what do you mean here by "compare"? And what is the
"mainstream"? If the mainstream is the one I got with wget, and if
"compare" means "see if they behave differently", so I have already
done it and they are both "good".

Thank you,
Andrea

Re: Slow I/O on USB media

[Alan Stern]

On Mon, 17 Jun 2019, Andrea Vai wrote:

> Il giorno lun, 17/06/2019 alle 12.14 -0400, Alan Stern ha scritto:
> > On Mon, 17 Jun 2019, Andrea Vai wrote:
> > 
> > > [...]
> > > 
> > > That happened ALL times, so I never encountered a kernel that made
> > me
> > > say "git bisect good".
> > 
> > Really?  That strongly suggests that the 4.20 kernel also should
> > have
> > been marked bad.  Did you really test it exactly the same way as all
> > the others?  That is, did you go through the entire procedure
> > starting
> > with "git checkout v4.20", then running the build script, then the
> > reboot and "uname -a", and then the test script?
> 
> well, honestly, no, because (sigh) I didn't know the "git checkout"
> command, sorry. I started with building 4.20 from the source
> downloaded with
> 
>  wget https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/snapshot/linux-4.20.tar.gz
> 
> , then said "git bisect good v4.20".
> 
> Is this different from "git checkout v4.20"? I hope it is, so we have
> found the mistake I have done.

In theory the results should be exactly the same.  But it doesn't hurt 
to check.

> > Compare the mainstream 4.20 kernel with the Fedora 4.20.13 kernel.  
> > Also, maybe compare the mainstream 4.20.13 with Fedora's 4.20.13.
> 
> Sorry, what do you mean here by "compare"? And what is the
> "mainstream"? If the mainstream is the one I got with wget, and if
> "compare" means "see if they behave differently", so I have already
> done it and they are both "good".

I was trying to point out that there may be a significant difference
between 4.20 and 4.20.13.  But if you say 4.20 behaves well, this 
doesn't matter.

At any rate, you are some commits you could try (beginning with "git 
checkout <commit>" and then running your scripts):

	c76cd634eb5b
	b1669432b355
	507413a5f88a
	a52fb43a5faa
	38fabca18fc4
	fc2fd5f0f1aa

These are all between 4.20 and 5.0-rc1.

Alan Stern

Re: Slow I/O on USB media

[Andrea Vai]

Il giorno lun, 17/06/2019 alle 13.28 -0400, Alan Stern ha scritto:
> On Mon, 17 Jun 2019, Andrea Vai wrote:
> 
> > Il giorno lun, 17/06/2019 alle 12.14 -0400, Alan Stern ha scritto:
> > > On Mon, 17 Jun 2019, Andrea Vai wrote:
> > > 
> > > > [...]
> > > > 
> > > > That happened ALL times, so I never encountered a kernel that
> made
> > > me
> > > > say "git bisect good".
> > > 
> > > Really?  That strongly suggests that the 4.20 kernel also should
> > > have
> > > been marked bad.  Did you really test it exactly the same way as
> all
> > > the others?  That is, did you go through the entire procedure
> > > starting
> > > with "git checkout v4.20", then running the build script, then
> the
> > > reboot and "uname -a", and then the test script?
> > 
> > well, honestly, no, because (sigh) I didn't know the "git
> checkout"
> > command, sorry. I started with building 4.20 from the source
> > downloaded with
> > 
> >  wget 
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/snapshot/linux-4.20.tar.gz
> > 
> > , then said "git bisect good v4.20".
> > 
> > Is this different from "git checkout v4.20"? I hope it is, so we
> have
> > found the mistake I have done.
> 
> In theory the results should be exactly the same.  But it doesn't
> hurt 
> to check.
> 
> > > Compare the mainstream 4.20 kernel with the Fedora 4.20.13
> kernel.  
> > > Also, maybe compare the mainstream 4.20.13 with Fedora's
> 4.20.13.
> > 
> > Sorry, what do you mean here by "compare"? And what is the
> > "mainstream"? If the mainstream is the one I got with wget, and if
> > "compare" means "see if they behave differently", so I have
> already
> > done it and they are both "good".
> 
> I was trying to point out that there may be a significant difference
> between 4.20 and 4.20.13.  But if you say 4.20 behaves well, this 
> doesn't matter.
> 
> At any rate, you are some commits you could try (beginning with
> "git 
> checkout <commit>" and then running your scripts):
> 
>         c76cd634eb5b
>         b1669432b355
>         507413a5f88a
>         a52fb43a5faa
>         38fabca18fc4
>         fc2fd5f0f1aa
> 
> These are all between 4.20 and 5.0-rc1.

Hi,
  these were all "good".

Then I ran another bisect (the sixth (!), more carefully, starting
from

git bisect good c76cd634eb5b
git bisect bad 241e39004581

), and it seems to give some consistent result.

I found that:

f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6 is the first bad commit
commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
Author: Jens Axboe <axboe@kernel.dk>
Date:   Thu Nov 1 16:36:27 2018 -0600

    scsi: kill off the legacy IO path
    
    This removes the legacy (non-mq) IO path for SCSI.
    
    Cc: linux-scsi@vger.kernel.org
    Acked-by: Himanshu Madhani <himanshu.madhani@cavium.com>
    Reviewed-by: Hannes Reinecke <hare@suse.com>
    Tested-by: Ming Lei <ming.lei@redhat.com>
    Reviewed-by: Omar Sandoval <osandov@fb.com>
    Acked-by: Martin K. Petersen <martin.petersen@oracle.com>
    Signed-off-by: Jens Axboe <axboe@kernel.dk>

:040000 040000 312373927bae1c6fd1da40ded2c12dfa5e4de71c 4eccbd2c84bf83cb2eb72a81514d59ebf12866b7 M	Documentation
:040000 040000 98de24b4fe20b82095f53f56c9193c5537d70ed0 8e2092780100205ae1c3723a598a89794a50677f M	drivers
:040000 040000 fbc10c84d3eb6b7933598018319f96767ee3a0f3 2523940c2819e8adb32758f5093e477da481ca65 M	include

I reverted it and the test succeeded.
Then I made a double check: "git clone" again; git checkout
3a7ea2c483a53fc89e336f69c6ee1d7defe00811 (the last good), and the test
succeded. Then git checkout f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
(the first bad) and the test failed; then reverted it and the test
succeded again.

Does it make sense?

Thanks,
Andrea

Re: Slow I/O on USB media

[Alan Stern]

On Mon, 1 Jul 2019, Andrea Vai wrote:

> > At any rate, you are some commits you could try (beginning with
> > "git 
> > checkout <commit>" and then running your scripts):
> > 
> >         c76cd634eb5b
> >         b1669432b355
> >         507413a5f88a
> >         a52fb43a5faa
> >         38fabca18fc4
> >         fc2fd5f0f1aa
> > 
> > These are all between 4.20 and 5.0-rc1.
> 
> Hi,
>   these were all "good".
> 
> Then I ran another bisect (the sixth (!), more carefully, starting
> from
> 
> git bisect good c76cd634eb5b
> git bisect bad 241e39004581
> 
> ), and it seems to give some consistent result.
> 
> I found that:
> 
> f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6 is the first bad commit
> commit f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
> Author: Jens Axboe <axboe@kernel.dk>
> Date:   Thu Nov 1 16:36:27 2018 -0600
> 
>     scsi: kill off the legacy IO path
>     
>     This removes the legacy (non-mq) IO path for SCSI.
>     
>     Cc: linux-scsi@vger.kernel.org
>     Acked-by: Himanshu Madhani <himanshu.madhani@cavium.com>
>     Reviewed-by: Hannes Reinecke <hare@suse.com>
>     Tested-by: Ming Lei <ming.lei@redhat.com>
>     Reviewed-by: Omar Sandoval <osandov@fb.com>
>     Acked-by: Martin K. Petersen <martin.petersen@oracle.com>
>     Signed-off-by: Jens Axboe <axboe@kernel.dk>
> 
> :040000 040000 312373927bae1c6fd1da40ded2c12dfa5e4de71c 4eccbd2c84bf83cb2eb72a81514d59ebf12866b7 M	Documentation
> :040000 040000 98de24b4fe20b82095f53f56c9193c5537d70ed0 8e2092780100205ae1c3723a598a89794a50677f M	drivers
> :040000 040000 fbc10c84d3eb6b7933598018319f96767ee3a0f3 2523940c2819e8adb32758f5093e477da481ca65 M	include
> 
> I reverted it and the test succeeded.
> Then I made a double check: "git clone" again; git checkout
> 3a7ea2c483a53fc89e336f69c6ee1d7defe00811 (the last good), and the test
> succeded. Then git checkout f664a3cc17b7d0a2bc3b3ab96181e1029b0ec0e6
> (the first bad) and the test failed; then reverted it and the test
> succeded again.
> 
> Does it make sense?

Yes, that does make sense.

What you should do next is report the problem to all the people
involved in that commit: Jens Axboe, Himanshu Madhani, and so on.  Be 
sure to CC: the USB mailing list and also linux-scsi@vger.kernel.org.

Given them a full description of the problem and explain how you
determined that this commit was the cause.  They should be able to help
figure out what's going wrong and fix it.

Alan Stern

Re: Slow I/O on USB media

[Greg KH]

On Sat, Jun 08, 2019 at 09:43:11AM +0200, Andrea Vai wrote:
> Il giorno gio 6 giu 2019 alle ore 16:48 Greg KH
> <gregkh@linuxfoundation.org> ha scritto:
> >
> > On Thu, Jun 06, 2019 at 04:00:52PM +0200, Andrea Vai wrote:
> > > Il giorno mer, 05/06/2019 alle 19.39 +0200, Greg KH ha scritto:
> > > > On Wed, Jun 05, 2019 at 06:23:58PM +0200, Andrea Vai wrote:
> > > > [...]
> > > >
> > > > > Anyway, I know that I can do all of this in a better way, and will
> > > > let
> > > > > you know.
> > > >
> > > > Yes, please do so, your steps above do not show much.
> > >
> > > Here I am with another question.
> > > What I have done so far:
> > >
> > > - booted with the last kernel I know to be working (4.20.13-
> > > 200.fc29.x86_64, installed from Fedora repos), checked that test runs
> >
> > We have no idea what is in a random distro kernel, sorry.
> >
> > So I would start with a kernel.org kernel.  That keeps things at an even
> > level, and you are using a "known good" configuration as well.
> >
> > > fine (2min to copy)
> > > - marked "git bisect good v4.20.13"
> > > - built the latest stable version:
> > >   - git clone https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git
> > >   - cp -v /boot/config-$(uname -r) .config
> > >   - make -j4 && make modules_install && make install && grub2-mkconfig -o /boot/grub2/grub.cfg
> > >   - grubby --set-default /boot/vmlinuz-5.2.0-rc3 (the last regular file listed in "ls -lrt /boot/v*")
> > > - rebooted with kernel 5.2.0-rc3, ran the test, took 49min to copy
> > > (!), thus marked "git bisect bad"
> > > - built again, and it turns out to be 4.20.0 (why is it earlier than
> > > 4.20.13?), rebooted with 4.20.0, ran the test and it took more than 15
> > > minutes so I killed the cp process, and marked it BAD, and obtained:
> > >
> > > The merge base 8fe28cb58bcb235034b64cbbb7550a8a43fd88be is bad.
> > > This means the bug has been fixed between
> > > 8fe28cb58bcb235034b64cbbb7550a8a43fd88be and
> > > [0f7c162c1df596e0bba04c26fc9cc497983bf32b].
> > >
> > > The output of "git bisect log" is:
> > >
> > > git bisect start
> > > # good: [0f7c162c1df596e0bba04c26fc9cc497983bf32b] Linux 4.20.13
> > > git bisect good 0f7c162c1df596e0bba04c26fc9cc497983bf32b
> > > # bad: [f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a] Linux 5.2-rc3
> > > git bisect bad f2c7c76c5d0a443053e94adb9f0918fa2fb85c3a
> > > # bad: [8fe28cb58bcb235034b64cbbb7550a8a43fd88be] Linux 4.20
> > > git bisect bad 8fe28cb58bcb235034b64cbbb7550a8a43fd88be
> > >
> > > I can understand that the bug was present before 4.20.13 (is that
> > > reasonable?), but how can I tell bisect to start at 4.20.13, which I
> > > know for sure to be working, and not from 4.20.0, which I actually
> > > don't care about?
> > >
> > > I am afraid I am missing something obvious, sorry
> >
> > As Alan said, 4.20 is older than 4.20.13.
> >
> > But, is the kernel.org version of 4.20.13 really "good" here?
> >
> > I would start with Linus's tree and stay away from the stable trees
> > for now.  As you end up with odd "leafs" that can confuse 'git bisect'
> > and everyone else.
> >
> > So start with 4.20.0.  Test that.  If it is "good", then great!
> 
> Hi,
>   there is also something else I don't understand.
> Every time I build a kernel, then after booting it "uname -a" shows
> something like
> 
> Linux [...] 4.19.0-rc5+ #12 SMP Sat Jun 8 00:26:42 CEST 2019 x86_64
> x86_64 x86_64 GNU/Linux
> 
> where the number after "#" increments by 1 from the previous build.
> 
> Now I have the same number (#12) after a new build, is it normal?

Maybe, sometimes an incremental build does not bump the .version number,
I don't remember exactly what causes that to increase.  It's somewhere
in the build scripts :)

> Furthermore, "ls -lrt /boot/v*" shows the last lines to be
> 
> -rw-r--r--. 1 root root 8648656  8 giu 00.35 /boot/vmlinuz-4.19.0-rc5+.old
> -rw-r--r--. 1 root root 8648656  8 giu 09.08 /boot/vmlinuz-4.19.0-rc5+
> 
> and "diff /boot/vmlinuz-4.19.0-rc5+.old /boot/vmlinuz-4.19.0-rc5+"
> shows they are identical. Why? I expected that each bisect would lead
> to a different kernel.

It should.

Are you sure they are really different?  'diff' works on text files, how
about running something like md5sum on the files to ensure they really
are, or are not, the same thing?

And sometimes, a bisection may cause things to change in files that you
do not actually require for building.  So the same output may happen.

> Assuming that the opposite can happen, does it mean that when I say
> i.e. "git bisect bad", then build a new kernel and see that is
> identical to the previous one I can run "git bisect bad" without
> booting into the new one and even making the test?
> 
> Another thing I don't understand is that I told 4.20.0 to be good, so
> I would expect that I don't need to test any older version, but as far
> as I know 4.19.0-rc5+ is older than 4.20.0, so why is it involved in
> the bisection?

Because it went down a subsystem branch that might have been based on a
much older tree.

Think about this workflow:
	- developer branches from 4.10.0
	- developer adds some patches to the branch
	- developer gets Linus to merge their branch into his 4.20-rc1
	  kernel release.

As a "point in time", between 4.19-final and 4.20-2, the development
worflow did step back to a 4.10.0 release, for those patches.

Now that's an extreme example, but lots of developers work off of the
last release (or close to it) and get their trees merged as part of the
merge window.  That is what will cause your kernel version to look like
it went back in time.

Hope this helps,

greg k-h