linux-acpi.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
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

  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).