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. > 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: > > Jun 15 08:58:25 strobe-jhalfs kernel: [ 193.315014] acpi_os_execute(1109) Adding acpi_ev_notify_dispatch+0x0/0x55 ffff8d7aa99a66e0 <ffff8d7aabb38480> > Jun 15 08:58:25 strobe-jhalfs kernel: [ 193.319929] acpi_os_execute_deferred_notify(853) End ffff8d7aa8758d00 acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e7eb0) > Jun 15 08:58:25 strobe-jhalfs kernel: [ 193.321242] 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 acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e70a0) > Jun 15 08:58:27 strobe-jhalfs kernel: [ 195.369234] acpi_os_execute_deferred_notify(851) Start ffff8d7aa8758240 acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e7a00) > Jun 15 08:58:28 strobe-jhalfs kernel: [ 196.387017] acpi_os_execute(1109) Adding acpi_ev_notify_dispatch+0x0/0x55 ffff8d7aa99a68c0 <ffff8d7aabb38540> > Jun 15 08:58:28 strobe-jhalfs kernel: [ 196.388508] acpi_os_execute_deferred_notify(853) End ffff8d7aa8758240 acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e7a00) > Jun 15 08:58:28 strobe-jhalfs kernel: [ 196.390128] acpi_os_execute_deferred_notify(851) Start ffff8d7aa8758b80 acpi_ev_notify_dispatch+0x0/0x55(ffff8d7aa84e7460) > Jun 15 08:58:29 strobe-jhalfs kernel: [ 197.208714] wlan1: deauthenticating from 7c:ff:4d:08:df:22 by local choice (Reason: 3=DEAUTH_LEAVING) > Jun 15 08:58:29 strobe-jhalfs kernel: [ 197.232214] ip (4614) used greatest stack depth: 11272 bytes left > Jun 15 08:58:29 strobe-jhalfs kernel: Kernel logging (proc) stopped. > Jun 15 08:58:29 strobe-jhalfs kernel: Kernel log daemon terminating. 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. > Steve Berman Sebastian
