lkml.org 
[lkml]   [2020]   [Jun]   [15]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
    /
    From
    SubjectRe: power-off delay/hang due to commit 6d25be57 (mainline)
    Date
    On Mon, 15 Jun 2020 17:58:46 +0200 Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:

    > On 2020-06-15 17:41:06 [+0200], Stephen Berman wrote:
    >> > If you do this "t" then there should be a lot of output on your console.
    >> > If you do this from an xterm then you can see the output after typing
    >> > "dmesg". The output should appear also in your system log.
    >>
    >> Ah, ok, I do see it in the log, it looks basically the same as the call
    >> trace I posted upthread. I wonder why there was no such output in the
    >> console, could there be some setting that suppresses it even though
    >> /proc/sys/kernel/sysrq has `1'?
    >
    > You have ignore_loglevel soo everything should appear on your console.
    > The is true for your tty / ctrl+alt+f1 but your xterm shell.

    Yet that appears not to be the case here, or I'm still doing something
    wrong 🤷

    >> There were in fact 99 "Start .* acpi_ev_notify_dispatch" messages and 98
    >> "End .* acpi_ev_notify_dispatch" messages. Here's the last of them
    >> before I rebooted:
    [...]
    >> acpi_os_execute_deferred_notify(851) Start ffff8d7aa8758a80
    >> acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e70a0)
    >> Jun 15 08:58:26 strobe-jhalfs kernel: [ 194.339017] acpi_os_execute(1109)
    >> Adding acpi_ev_notify_dispatch+0x0/0x55 ffff8d7aa99a6730 <ffff8d7aabb384c0>
    >> Jun 15 08:58:27 strobe-jhalfs kernel: [ 195.363005] acpi_os_execute(1109)
    >> Adding acpi_ev_notify_dispatch+0x0/0x55 ffff8d7aa99a6780 <ffff8d7aabb38500>
    >> Jun 15 08:58:27 strobe-jhalfs kernel: [ 195.367978]
    >> acpi_os_execute_deferred_notify(853) End ffff8d7aa8758a80
    [...]

    > Okay. So there is "Adding" of four events/work items in total, each
    > almost every second.
    > Processing of one work-item took two seconds, the other one took a
    > second. These events are "old" so I don't see the "adding" line for the
    > Start/End.
    > You could look in the log for ffff8d7aa8758a80 to seen when it was
    > enqueued but it feels like ACPI enqueues more events then it is capable
    > of processing.

    It's there, 196 lines above the Start ffff8d7aa8758a80 line:

    Jun 15 08:56:58 strobe-jhalfs kernel: [ 106.275356] acpi_os_execute(1109) Adding acpi_ev_notify_dispatch+0x0/0x55 ffff8d7aa84e70a0 <ffff8d7aa8758a80>

    Steve Berman

    \
     
     \ /
      Last update: 2020-06-15 18:19    [W:2.568 / U:0.024 seconds]
    ©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site