From: Stephen Berman <stephen.berman@gmx.net>
To: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
Cc: Thomas Gleixner <tglx@linutronix.de>,
Peter Zijlstra <peterz@infradead.org>,
linux-kernel@vger.kernel.org, linux-acpi@vger.kernel.org
Subject: Re: power-off delay/hang due to commit 6d25be57 (mainline)
Date: Mon, 15 Jun 2020 09:58:00 +0200 [thread overview]
Message-ID: <874krcsquv.fsf@gmx.net> (raw)
In-Reply-To: 20200614171005.3zy673p6bpwoqnmq@linutronix.de
On Sun, 14 Jun 2020 19:10:05 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> On 2020-06-14 14:12:18 [+0200], Stephen Berman wrote:
[...]
>> What am I supposed to do after "echo t > /proc/sysrq-trigger"? Both
>> before and after doing that I get an error trying to open the file:
>>
>> root [ ~ ]# cat /proc/sysrq-trigger
>> cat: /proc/sysrq-trigger: Input/output error
>
> echo "t > /proc/sysrq-trigger"
>
> not cat.
Ok, sorry, I had misunderstood, but now I've looked at the
documentation. I had in fact already done `echo t >
/proc/sysrq-trigger' in an xterm (as root) and there was no output.
Later, after booting kernel 5.1.0 because of the message flooding with
5.6.4, I did `echo t > /proc/sysrq-trigger' in a virtual tty (also as
root) and the only output was: `[ <timestamp>] sysrq: Show State'. Is
this expected? (In /proc/sys/kernel/sysrq there is `1'.) I couldn't
try it in a 5.6.4 virtual tty because of the message flooding (see
below).
[...]
>> I applied this patch to 5.6.4 and recompiled, and on the next boot with
>> that kernel, the kernel buffer (and kernel and system logs) began to get
>> flooded with these messages:
>>
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.943987]
>> acpi_os_execute_deferred(843) Start ffff8fb82c7b6500
>> 000000003edf1e05(ffff8fb82c492990)
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944102] acpi_os_execute(1101)
>> Adding acpi_ev_asynch_enable_gpe+0x0/0x2f ffff8fb82c492990
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944104]
>> acpi_os_execute_deferred(845) End ffff8fb82c7b6500
>> 000000003edf1e05(ffff8fb82c492990)
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944105]
>> acpi_os_execute_deferred(843) Start ffff8fb82b844800
>> 000000002ba560ea(ffff8fb82c492990)
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944124]
>> acpi_os_execute_deferred(845) End ffff8fb82b844800
>> 000000002ba560ea(ffff8fb82c492990)
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944288]
>> acpi_os_execute_deferred(843) Start ffff8fb82c7b6540
>> 000000003edf1e05(ffff8fb82c492990)
>> Jun 14 10:37:13 strobe-jhalfs kernel: [ 5.944387] acpi_os_execute(1101)
>> Adding acpi_ev_asynch_enable_gpe+0x0/0x2f ffff8fb82c492990
>>
>> and so on without stopping. I could start X and avoid seeing the
>> messages, but was afraid the logs would fill up the root partition if I
>> let it keep going, so I rebooted with another kernel.
>>
>> Was this message flood because I booted with "ignore_loglevel
>> initcall_debug"? In the logs there are also lots of messages like this:
>
> Is there a acpi_os_execute_* flood? The *few* at what appears to system
> startup and might be normal. If there appear *many* more and are
> constantly printing (check with dmesg) then we might be to something.
The kernel log shows 305 of these messages in the 4 minutes and 17
seconds between the start of klogd and when I rebooted.
[...]
> I attached the updated acpi patch. It limits the prints to the
> kacpi_notify_wq queue which appears to stuck at shutdown.
I applied this patch and rebuilt the kernel. After booting 5.6.4 this
morning there was again message flooding and this time I was unable to
log in because of it, so had to do a hard reboot and booted with 5.1.0.
The kernel log shows 207 acpi_os_execute_deferred_notify messages in 3
minutes and 6 seconds; here are the first:
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.943848] acpi_os_execute(1109) Adding acpi_ev_asynch_enable_gpe+0x0/0x2f ffff8d7aaba18990 <ffff8d7aab157fc0>
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.943851] acpi_os_execute_deferred_notify(851) Start ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.943865] acpi_os_execute_deferred_notify(853) End ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944104] acpi_os_execute(1109) Adding acpi_ev_asynch_enable_gpe+0x0/0x2f ffff8d7aaba18990 <ffff8d7aab157fc0>
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944106] acpi_os_execute_deferred_notify(851) Start ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944115] acpi_os_execute_deferred_notify(853) End ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944406] acpi_os_execute(1109) Adding acpi_ev_asynch_enable_gpe+0x0/0x2f ffff8d7aaba18990 <ffff8d7aab157fc0>
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944408] acpi_os_execute_deferred_notify(851) Start ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
Jun 15 08:55:22 strobe-jhalfs kernel: [ 5.944417] acpi_os_execute_deferred_notify(853) End ffff8d7aab157fc0 acpi_ev_asynch_enable_gpe+0x0/0x2f(ffff8d7aaba18990)
> The interesting part is to see if there is a acpi_os_execute() adding a
> specific event multiple times which does not complete. Maybe at runtime,
> maybe at shutdown time. If that is the case then ignoring this specific
> event might fix the shutdown problem. With all this information so far,
> I don't see a relation with this problem and the commit…
In those 3 minutes and 8 seconds there were 5 "Adding
acpi_ev_asynch_enable_gpe" messages at the beginning, then 185 "Adding
acpi_ev_notify_dispatch" messages, which kept coming until I rebooted.
Steve Berman
next prev parent reply other threads:[~2020-06-15 7:58 UTC|newest]
Thread overview: 42+ messages / expand[flat|nested] mbox.gz Atom feed top
[not found] <87v9l65d2y.fsf@gmx.net>
[not found] ` <20200513220428.4nksinis2qs5dtmh@linutronix.de>
[not found] ` <87mu6aurfn.fsf@gmx.net>
[not found] ` <20200522164012.ynyvrjompv42jtmx@linutronix.de>
[not found] ` <87y2owwo2o.fsf@rub.de>
[not found] ` <20200609202339.cgy57twm2zdtjhje@linutronix.de>
[not found] ` <87tuzjcovq.fsf@gmx.net>
[not found] ` <20200610102514.4vdzu5u7d6vnpicn@linutronix.de>
[not found] ` <87imfyh6yx.fsf@gmx.net>
[not found] ` <87wo4dligz.fsf@gmx.net>
2020-06-12 11:01 ` power-off delay/hang due to commit 6d25be57 (mainline) Sebastian Andrzej Siewior
2020-06-14 12:12 ` Stephen Berman
2020-06-14 17:10 ` Sebastian Andrzej Siewior
2020-06-15 7:58 ` Stephen Berman [this message]
2020-06-15 14:51 ` Sebastian Andrzej Siewior
2020-06-15 15:41 ` Stephen Berman
2020-06-15 15:58 ` Sebastian Andrzej Siewior
2020-06-15 16:19 ` Stephen Berman
2020-06-15 16:32 ` Sebastian Andrzej Siewior
2020-06-16 7:14 ` Stephen Berman
2020-06-16 7:38 ` Sebastian Andrzej Siewior
2020-06-16 8:13 ` Stephen Berman
2020-06-16 15:55 ` Sebastian Andrzej Siewior
2020-06-16 20:28 ` Stephen Berman
2020-06-17 14:27 ` Sebastian Andrzej Siewior
2020-06-17 21:09 ` Stephen Berman
2020-06-24 20:11 ` Sebastian Andrzej Siewior
2020-06-24 21:49 ` Stephen Berman
2020-07-14 13:44 ` Sebastian Andrzej Siewior
2020-07-14 13:54 ` Rafael J. Wysocki
2020-07-14 14:11 ` Sebastian Andrzej Siewior
2020-07-14 15:53 ` Rafael J. Wysocki
2020-07-14 16:10 ` Sebastian Andrzej Siewior
2020-08-11 10:27 ` Sebastian Andrzej Siewior
2020-08-11 14:02 ` Rafael J. Wysocki
2020-07-19 10:07 ` Stephen Berman
2020-08-11 11:58 ` Stephen Berman
2020-08-11 13:29 ` Sebastian Andrzej Siewior
2020-08-11 14:34 ` Rafael J. Wysocki
2020-08-11 15:25 ` Sebastian Andrzej Siewior
[not found] ` <87ft8tayic.fsf@gmx.net>
2020-08-11 18:49 ` Sebastian Andrzej Siewior
2020-10-06 21:49 ` Sebastian Andrzej Siewior
2020-10-07 16:18 ` Rafael J. Wysocki
2020-10-26 17:20 ` Sebastian Andrzej Siewior
2020-12-02 18:03 ` Sebastian Andrzej Siewior
2020-12-02 18:31 ` Rafael J. Wysocki
2020-12-02 19:13 ` Rafael J. Wysocki
2020-12-31 20:46 ` Rafael J. Wysocki
2021-01-02 11:03 ` Rafael J. Wysocki
2021-01-04 15:38 ` Stephen Berman
2021-01-24 13:49 ` Stephen Berman
2021-01-25 16:25 ` Rafael J. Wysocki
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=874krcsquv.fsf@gmx.net \
--to=stephen.berman@gmx.net \
--cc=bigeasy@linutronix.de \
--cc=linux-acpi@vger.kernel.org \
--cc=linux-kernel@vger.kernel.org \
--cc=peterz@infradead.org \
--cc=tglx@linutronix.de \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).