You are not logged in.

#1 2023-09-11 16:14:33

laktak
Member
Registered: 2017-09-04
Posts: 31

scsi_eh_1 process high cpu after upgrading to 6.5.2

I've upgraded several VMs

- from Linux arch 6.4.12-arch1-1 #1 SMP PREEMPT_DYNAMIC Thu, 24 Aug 2023 00:38:14 +0000 x86_64 GNU/Linux
- to Linux arch 6.5.2-arch1-1 #1 SMP PREEMPT_DYNAMIC Wed, 06 Sep 2023 21:01:01 +0000 x86_64 GNU/Linux

and in all of them the scsi_eh_1 process eats 10-15% CPU.

I can't find any errors in the logs. When I go back to a snapshot with 6.4.12 the problem disappears. The FS is btrfs.

scsi_eh should be the scsi error handler so I've tried to enable logging (https://github.com/ibm-s390-linux/s390- … ging_level) but I see no output in dmesg/journalctl.

How can I find out what is causing this?

Offline

#2 2023-09-11 18:04:12

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

laktak wrote:

How can I find out what is causing this?

https://wiki.archlinux.org/title/Kernel … egressions

Offline

#3 2023-09-12 11:26:23

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

Thank you. I've compared the kernels and the problem appears after going from 6.4.12 to 6.5.

https://cdn.kernel.org/pub/linux/kernel … ngeLog-6.5 has several changes regarding SCSI so I'll try to contact the author.

Offline

#4 2023-09-12 14:46:53

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

Please consider bisecting between 6.4 and 6.5 or reverting just those commits to see if they resolve the issue before contacting upstream.

Offline

#5 2023-09-12 19:07:46

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

Yes, I'm trying but the VMs are rather small and are taking forever to build.

Offline

#6 2023-09-12 19:16:50

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

If you need some help with the bisection I can build the kernel packages for you.  If you want my help I would need to know your current bisection progress `git bisect log` and preferably the kernel config you are using for instance the one from 6.5.2-arch1-1

Offline

#7 2023-09-12 20:24:53

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

So far I only managed to build and install https://aur.archlinux.org/packages/linux-git because I saw there were additional commits regarding SCSI. Unfortunately they did not fix the bug.

The new kernel also stays a long time at ":: Triggering uevents..." at boot before proceeding.

It would be great if you could help me bisect from 6.4.12 to 6.5.

kernel config: https://pastebin.com/gYLwvbeg

There are lots of commits that mention SCSI but one references scsi_eh:

commit 3d848ca1ebc8d8864f25bd461914c93eff82a2d2
Author: Niklas Cassel <niklas.cassel@wdc.com>
Date:   Thu May 11 03:13:37 2023 +0200

Offline

#8 2023-09-12 21:36:33

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

https://drive.google.com/file/d/1SzRGbE … sp=sharing linux-6.5-1.1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1k-FP2A … sp=sharing linux-headers-6.5-1.1-x86_64.pkg.tar.zst
Please test that 6.5 built with Arch's 6.5 config has the issue.  I am building the first bisection point assuming it did:

$ git bisect start
status: waiting for both good and bad commits
$ git bisect good v6.4
status: waiting for bad commit, 1 good commit known
$ git bisect bad v6.5
Bisecting: 7364 revisions left to test after this (roughly 13 steps)
[b775d6c5859affe00527cbe74263de05cfe6b9f9] Merge tag 'mips_6.5' of git://git.kernel.org/pub/scm/linux/kernel/git/mips/linux

Edit:
https://drive.google.com/file/d/1mzFisD … sp=sharing linux-6.4.r7309.gb775d6c5859a-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1FN7ufH … sp=sharing linux-headers-6.4.r7309.gb775d6c5859a-1-x86_64.pkg.tar.zst

Last edited by loqs (2023-09-12 21:53:39)

Offline

#9 2023-09-13 07:01:02

MoZhonghua
Member
Registered: 2023-09-13
Posts: 4

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

loqs wrote:

https://drive.google.com/file/d/1SzRGbE … sp=sharing linux-6.5-1.1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1k-FP2A … sp=sharing linux-headers-6.5-1.1-x86_64.pkg.tar.zst
Please test that 6.5 built with Arch's 6.5 config has the issue.  I am building the first bisection point assuming it did:

$ git bisect start
status: waiting for both good and bad commits
$ git bisect good v6.4
status: waiting for bad commit, 1 good commit known
$ git bisect bad v6.5
Bisecting: 7364 revisions left to test after this (roughly 13 steps)
[b775d6c5859affe00527cbe74263de05cfe6b9f9] Merge tag 'mips_6.5' of git://git.kernel.org/pub/scm/linux/kernel/git/mips/linux

Edit:
https://drive.google.com/file/d/1mzFisD … sp=sharing linux-6.4.r7309.gb775d6c5859a-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1FN7ufH … sp=sharing linux-headers-6.4.r7309.gb775d6c5859a-1-x86_64.pkg.tar.zst


Same issue in my virtual machines. Following kernels tested:

bad: 6.5.2-arch1-1

ok: 6.1.52-1-lts
ok: 6.4.0-1.1-07309-gb775d6c5859a

Offline

#10 2023-09-13 08:39:41

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

Thanks loqs! Same here:

bad: 6.5.0-1.1

ok: 6.4.0-1.1-07309-gb775d6c5859a

Offline

#11 2023-09-13 10:49:24

seth
Member
Registered: 2012-09-03
Posts: 54,169

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

I can't find any errors in the logs

I've tried to enable logging … but I see no output in dmesg/journalctl.

"Tried" how?

scsi_logging_level -g
sudo scsi_logging_level -a 7 -s  # should spam your log mightily

Do you have an optical drive?

Offline

#12 2023-09-13 11:08:26

MoZhonghua
Member
Registered: 2023-09-13
Posts: 4

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

seth wrote:

Do you have an optical drive?

I have an optical drive in VMWare virtal machine, and I don't have an physical optical drive on my host machine, so this drive is set with "connected" and "connect at startup" disabled.

When I delete optical drive from my virtual machine, the problem goes away!  (tested with kernel 6.5.2-arch1-1).

Some log with "sudo scsi_logging_level -a 7 -s"

https://pastebin.com/f2LQ8kQD

Last edited by MoZhonghua (2023-09-13 11:21:53)

Offline

#13 2023-09-13 11:23:50

seth
Member
Registered: 2012-09-03
Posts: 54,169

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

Do you need some logs with "sudo scsi_logging_level -a 7 -s"?

I don't expect that helping to narrow down on the cause (beyond what my gut told you wink )
It was more to contest the "no log output" situation.

There's a whole bunch of commits that look like sring-clean by Christoph Hellwig and then there's

commit 8270cb10c0681d52fce508f827dfa1688d3acc3a
Author: Jordy Zomer <jordyzomer@google.com>
Date:   Sat Jun 17 12:38:28 2023 +0100

    cdrom: Fix spectre-v1 gadget

Only the latter isn't in the wider context of more generic block device code changes, so I'd maybe look there first (unless it was backported to 6.4)


Edit: Just noticed there're two users!
==================================
Wait for a situation description from laktak first.

Last edited by seth (2023-09-13 11:25:19)

Offline

#14 2023-09-13 11:38:58

MoZhonghua
Member
Registered: 2023-09-13
Posts: 4

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

More tests:

1. with optical disk but not connected, kernel 6.5.2: many spurious error messages like this (full log: https://pastebin.com/f2LQ8kQD )

[  300.306311] sr 0:0:0:0: [sr0] tag#0 scsi host busy 1 failed 0
[  300.326421] scsi host0: Waking error handler thread
[  300.326435] scsi host0: scsi_eh_0: waking up 0/1/1

2. with optical disk and using an ISO file, kernel 6.5.2: same problem

3. with or without optical disk, kernel 6.4.0: no problem and no error messages

Offline

#15 2023-09-13 11:47:48

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

https://drive.google.com/file/d/1Zt97LF … sp=sharing linux-6.4.r4247.g3a8a670eeeaa-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1xwqcXa … sp=sharing linux-headers-6.4.r4247.g3a8a670eeeaa-1-x86_64.pkg.tar.zst

Offline

#16 2023-09-13 11:56:10

MoZhonghua
Member
Registered: 2023-09-13
Posts: 4

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

loqs wrote:

https://drive.google.com/file/d/1Zt97LF … sp=sharing linux-6.4.r4247.g3a8a670eeeaa-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1xwqcXa … sp=sharing linux-headers-6.4.r4247.g3a8a670eeeaa-1-x86_64.pkg.tar.zst


bad: 6.5.2-arch1-1

ok: 6.1.52-1-lts
ok: 6.4.0-1.1-07309-gb775d6c5859a
ok: 6.4.0-1.1-04247-g3a8a670eeeaa

Offline

#17 2023-09-13 12:35:53

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

6.5.3-arch1 with 8270cb10c0681d52fce508f827dfa1688d3acc3a reverted

https://drive.google.com/file/d/1TfRS7t … sp=sharing linux-6.5.3.arch1-1.1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1NbgmjJ … sp=sharing linux-headers-6.5.3.arch1-1.1-x86_64.pkg.tar.zst
Edit:
If that was not the cause

$ git bisect good
Bisecting: 3681 revisions left to test after this (roughly 12 steps)
[56cbceab928d7ac3702de172ff8dcc1da2a6aaeb] Merge tag 'usb-6.5-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/usb

https://drive.google.com/file/d/1F20Nu2 … sp=sharing linux-6.4.r10992.g56cbceab928d-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1V_i78p … sp=sharing linux-headers-6.4.r10992.g56cbceab928d-1-x86_64.pkg.tar.zst

I made a mistake with linux-6.4.r4247.g3a8a670eeeaa-1-x86_64.pkg.tar.zst because I marked b775d6c5859affe00527cbe74263de05cfe6b9f9 as bad when you had tested it as good.
Correct git log

]$ git bisect log
git bisect start
# status: waiting for both good and bad commits
# good: [6995e2de6891c724bfeb2db33d7b87775f913ad1] Linux 6.4
git bisect good 6995e2de6891c724bfeb2db33d7b87775f913ad1
# bad: [2dde18cd1d8fac735875f2e4987f11817cc0bc2c] Linux 6.5
git bisect bad 2dde18cd1d8fac735875f2e4987f11817cc0bc2c
# good: [b775d6c5859affe00527cbe74263de05cfe6b9f9] Merge tag 'mips_6.5' of git://git.kernel.org/pub/scm/linux/kernel/git/mips/linux
git bisect good b775d6c5859affe00527cbe74263de05cfe6b9f9

Last edited by loqs (2023-09-13 13:00:42)

Offline

#18 2023-09-13 13:50:38

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

bad: 6.5.3-arch1-1.1
bad: 6.4.0-1-10992-g56cbceab928d

Offline

#19 2023-09-13 14:34:15

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

$ git bisect bad
Bisecting: 1805 revisions left to test after this (roughly 11 steps)
[b30d7a77c53ec04a6d94683d7680ec406b7f3ac8] Merge tag 'perf-tools-for-v6.5-1-2023-06-28' of git://git.kernel.org/pub/scm/linux/kernel/git/perf/perf-tools-next

https://drive.google.com/file/d/1ZMv5pU … sp=sharing linux-6.4.r9186.gb30d7a77c53e-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1LFcQSn … sp=sharing linux-headers-6.4.r9186.gb30d7a77c53e-1-x86_64.pkg.tar.zst

Offline

#20 2023-09-13 14:41:27

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

good: 6.4.0-1-09186-gb30d7a77c53e

Offline

#21 2023-09-13 14:46:08

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

seth wrote:
scsi_logging_level -g
sudo scsi_logging_level -a 7 -s  # should spam your log mightily

Not sure what I did wrong before but this produces logs. Thanks.

Offline

#22 2023-09-13 15:02:47

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

$ git bisect good
Bisecting: 895 revisions left to test after this (roughly 10 steps)
[dfab92f27c600fea3cadc6e2cb39f092024e1fef] Merge tag 'nfs-for-6.5-1' of git://git.linux-nfs.org/projects/trondmy/linux-nfs

https://drive.google.com/file/d/11gecSQ … sp=sharing linux-6.4.r10096.gdfab92f27c60-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1vtGQ4h … sp=sharing linux-headers-6.4.r10096.gdfab92f27c60-1-x86_64.pkg.tar.zst
Edit:
6.5.3-arch1 with https://lore.kernel.org/linux-ide/20230 … l.org/T/#u applied:

https://drive.google.com/file/d/1nYW-4w … sp=sharing linux-6.5.3.arch1-1.2-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1y3NU8K … sp=sharing linux-headers-6.5.3.arch1-1.2-x86_64.pkg.tar.zst

Last edited by loqs (2023-09-13 15:51:54)

Offline

#23 2023-09-13 19:25:03

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

bad: 6.5.3-arch1-1.2
bad: 6.4.0-1-10096-gdfab92f27c60

Offline

#24 2023-09-13 20:20:56

loqs
Member
Registered: 2014-03-06
Posts: 17,728

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

$ git bisect bad
Bisecting: 476 revisions left to test after this (roughly 9 steps)
[28968f384be3c064d66954aac4c534a5e76bf973] Merge tag 'pinctrl-v6.5-1' of git://git.kernel.org/pub/scm/linux/kernel/git/linusw/linux-pinctrl

https://drive.google.com/file/d/1WpabY3 … sp=sharing linux-6.4.r9619.g28968f384be3-1-x86_64.pkg.tar.zst
https://drive.google.com/file/d/1TPKs7w … sp=sharing linux-headers-6.4.r9619.g28968f384be3-1-x86_64.pkg.tar.zst

Offline

#25 2023-09-13 20:57:40

laktak
Member
Registered: 2017-09-04
Posts: 31

Re: scsi_eh_1 process high cpu after upgrading to 6.5.2

bad: 6.4.0-1-09619-g28968f384be3

Offline

Board footer

Powered by FluxBB