Rafael J. Wysocki | 9 Aug 2012 11:41
Picon
Gravatar

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Thursday, August 09, 2012, Athlion wrote:
> Thanks for the swift reply!
> 
> If I choose processors, I get (among other normal things) this:

What happens if you choose "core"?

> [  305.156134] suspend debug: Waiting for 5 seconds.
> [  310.149418] Enabling non-boot CPUs ...
> [  310.152933] Booting Node 0 Processor 1 APIC 0x1
> [  310.163948] Disabled fast string operations
> [  310.166366] ACPI Exception: AE_BAD_PARAMETER, Returned by Handler
> for [EmbeddedControl] (20120320/evregion-501)
> [  310.166369] ACPI Error: Method parse/execution failed
> [\_SB_.PCI0.LPC_.EC__.LPMD] (Node ffff88011824dc58), AE_BAD_PARAMETER
> (20120320/psparse-536)
> [  310.166374] ACPI Error: Method parse/execution failed
> [\_PR_.CPU0._PPC] (Node ffff88011827d118), AE_BAD_PARAMETER
> (20120320/psparse-536)
> [  310.166377] ACPI Error: Method parse/execution failed
> [\_PR_.CPU1._PPC] (Node ffff88011827d938), AE_BAD_PARAMETER
> (20120320/psparse-536)
> [  310.166382] ACPI Exception: AE_BAD_PARAMETER, Evaluating _PPC
> (20120320/processor_perflib-140)
> [  310.166393] CPU1 is up
> [  310.166455] Booting Node 0 Processor 2 APIC 0x2
> [  310.177563] Disabled fast string operations
> [  310.180057] ACPI Exception: AE_BAD_PARAMETER, Returned by Handler
> for [EmbeddedControl] (20120320/evregion-501)
> [  310.180061] ACPI Error: Method parse/execution failed
(Continue reading)

Athlion | 9 Aug 2012 19:14
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Thu, Aug 9, 2012 at 12:41 PM, Rafael J. Wysocki <rjw <at> sisk.pl> wrote:
> On Thursday, August 09, 2012, Athlion wrote:
>> Thanks for the swift reply!
>>
>> If I choose processors, I get (among other normal things) this:
>
> What happens if you choose "core"?

Both core and processors always exhibit the same ACPI errors.

>> I do not get these ACPI Error and ACPI Exceptions in a normal run. Is
>> this normal?
>
> No, it is not.
>
>> Does it indicate a problem?
>
> A small one.  It indicates that P-states as defined in the BIOS aren't
> usable to the ACPI cpufreq driver.  There also seems to be a problem with
> the handling of the embedded controller, which may be more serious.

Should I report this to the ACPI list?

>> The dmesg of the pm-suspend after i have
>> # echo "processors" > /sys/power/pm_test
>> can be found here: https://dl.dropbox.com/u/63420/processors.txt
>>
>> The dmesg of a full pm-suspend run is here
>> https://dl.dropbox.com/u/63420/full.txt
>
(Continue reading)

Athlion | 11 Aug 2012 17:18
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

Ok, this thing happened again! Whatsmore, this happened on pm-suspend
while on [core].

The kernel output this:
Aug 11 17:59:16 localhost logger: LID closed
Aug 11 17:59:16 localhost kernel: [32512.391116] EXT4-fs (sda1):
re-mounted. Opts: discard,barrier=0,commit=0
Aug 11 17:59:17 localhost kernel: [32512.520905] wlan0:
deauthenticating from 00:13:33:a1:23:46 by local choice (reason=3)
Aug 11 17:59:17 localhost kernel: [32512.530786] cfg80211: Calling
CRDA to update world regulatory domain
Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0): now unmanaged
Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0): device
state change: activated -> unmanaged (reason 'removed') [100 10 36]
Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0):
deactivating device (reason 'removed') [36]
Aug 11 17:59:17 localhost dhcpcd[12635]: received SIGTERM, stopping
Aug 11 17:59:17 localhost dhcpcd[12635]: wlan0: removing interface
Aug 11 17:59:17 localhost dhcpcd[12635]: wlan0: del_route: No such device
Aug 11 17:59:17 localhost dhcpcd[12635]: del_address: No such device
Aug 11 17:59:17 localhost kernel: [32512.607181] ehci_hcd
0000:00:1d.0: remove, state 1
Aug 11 17:59:17 localhost kernel: [32512.607212] usb usb2: USB
disconnect, device number 1
Aug 11 17:59:17 localhost kernel: [32512.607214] usb 2-1: USB
disconnect, device number 2
Aug 11 17:59:17 localhost kernel: [32512.612488] ehci_hcd
0000:00:1d.0: USB bus 2 deregistered
Aug 11 17:59:17 localhost kernel: [32512.612528] ehci_hcd
0000:00:1a.0: remove, state 1
(Continue reading)

Rafael J. Wysocki | 12 Aug 2012 00:08
Picon
Gravatar

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Saturday, August 11, 2012, Athlion wrote:
> Ok, this thing happened again! Whatsmore, this happened on pm-suspend
> while on [core].
> 
> The kernel output this:

The majority of the messages below are not from the kernel.  The
kernel's messages contain the string "kernel:".

> Aug 11 17:59:16 localhost logger: LID closed
> Aug 11 17:59:16 localhost kernel: [32512.391116] EXT4-fs (sda1):
> re-mounted. Opts: discard,barrier=0,commit=0
> Aug 11 17:59:17 localhost kernel: [32512.520905] wlan0:
> deauthenticating from 00:13:33:a1:23:46 by local choice (reason=3)
> Aug 11 17:59:17 localhost kernel: [32512.530786] cfg80211: Calling
> CRDA to update world regulatory domain
> Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0): now unmanaged
> Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0): device
> state change: activated -> unmanaged (reason 'removed') [100 10 36]
> Aug 11 17:59:17 localhost NetworkManager[794]: <info> (wlan0):
> deactivating device (reason 'removed') [36]
> Aug 11 17:59:17 localhost dhcpcd[12635]: received SIGTERM, stopping
> Aug 11 17:59:17 localhost dhcpcd[12635]: wlan0: removing interface
> Aug 11 17:59:17 localhost dhcpcd[12635]: wlan0: del_route: No such device
> Aug 11 17:59:17 localhost dhcpcd[12635]: del_address: No such device
> Aug 11 17:59:17 localhost kernel: [32512.607181] ehci_hcd
> 0000:00:1d.0: remove, state 1
> Aug 11 17:59:17 localhost kernel: [32512.607212] usb usb2: USB
> disconnect, device number 1
> Aug 11 17:59:17 localhost kernel: [32512.607214] usb 2-1: USB
(Continue reading)

Athlion | 12 Aug 2012 13:01
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Sun, Aug 12, 2012 at 1:08 AM, Rafael J. Wysocki <rjw <at> sisk.pl> wrote:
> This seems to be the last kernel message you've got.
>
> It looks like there's a problem with a power management notifier within
> the kernel.  Perhaps a race condition, since it is not reproducible 100%
> of the time.
>
> Does it happen if you don't use the lid to trigger suspend?
>
> Rafael

No, it does not.

If I don't use the lid, the suspend succeeds 100% of the time (at
least, I have achieved over 4 days of uptime by using the
logout/suspend button of xfce, I never could stand not closing the lid
for more...)

What I don't know exactly is how to begin tracking this problem down.
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo <at> vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Athlion | 12 Aug 2012 15:26
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Sun, Aug 12, 2012 at 2:01 PM, Athlion <athlion <at> gmail.com> wrote:
> On Sun, Aug 12, 2012 at 1:08 AM, Rafael J. Wysocki <rjw <at> sisk.pl> wrote:
>> This seems to be the last kernel message you've got.
>>
>> It looks like there's a problem with a power management notifier within
>> the kernel.  Perhaps a race condition, since it is not reproducible 100%
>> of the time.
>>
>> Does it happen if you don't use the lid to trigger suspend?
>>
>> Rafael
>
> No, it does not.
>
> If I don't use the lid, the suspend succeeds 100% of the time (at
> least, I have achieved over 4 days of uptime by using the
> logout/suspend button of xfce, I never could stand not closing the lid
> for more...)
>
> What I don't know exactly is how to begin tracking this problem down.

Furthermore, the suspend actually *happens* if I initiate a shutdown
or reboot procedure, right after the point where the system says
killing all processes. On resume, the shutdown/reboot resumes
normally.
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo <at> vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

(Continue reading)

Rafael J. Wysocki | 12 Aug 2012 23:03
Picon
Gravatar

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Sunday, August 12, 2012, Athlion wrote:
> On Sun, Aug 12, 2012 at 2:01 PM, Athlion <athlion <at> gmail.com> wrote:
> > On Sun, Aug 12, 2012 at 1:08 AM, Rafael J. Wysocki <rjw <at> sisk.pl> wrote:
> >> This seems to be the last kernel message you've got.
> >>
> >> It looks like there's a problem with a power management notifier within
> >> the kernel.  Perhaps a race condition, since it is not reproducible 100%
> >> of the time.
> >>
> >> Does it happen if you don't use the lid to trigger suspend?
> >>
> >> Rafael
> >
> > No, it does not.
> >
> > If I don't use the lid, the suspend succeeds 100% of the time (at
> > least, I have achieved over 4 days of uptime by using the
> > logout/suspend button of xfce, I never could stand not closing the lid
> > for more...)
> >
> > What I don't know exactly is how to begin tracking this problem down.
> 
> Furthermore, the suspend actually *happens* if I initiate a shutdown
> or reboot procedure, right after the point where the system says
> killing all processes. On resume, the shutdown/reboot resumes
> normally.

There seems to be an input event handling race condition with system suspend
on your machine.  I wonder if it's related to the specific system configuration,
though, because no one else has reported anything like this before.
(Continue reading)

Athlion | 13 Aug 2012 09:13
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

Thanks,

Here is my dmesg from a clean boot:

https://dl.dropbox.com/u/63420/dmesg.txt

Now that I scanned it more thoroughly I found these:

[    0.363136] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query ignored
and
[    0.387856] PCI: Using host bridge windows from ACPI; if necessary,
use "pci=nocrs" and report a bug

my /proc/cmdline is:
BOOT_IMAGE=/boot/vmlinuz-linux
root=UUID=44cf687d-4827-4765-8758-98d44a745d07 ro quiet
resume=/dev/sda2

maybe they indicate a lurking problem?

(in parallel, I will try booting with pci=nocrs and report back)

And there are other people having this issue, some from way back, as
can be seen here
https://bbs.archlinux.org/viewtopic.php?id=144381
(Don't be fooled by the linux 3.4.x reference in the title, it happens
with older kernels, too)

Some of them have found the "solution" to be "never close the lid" but
this is unacceptable, for me.
(Continue reading)

Athlion | 13 Aug 2012 09:27
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

And this is the dmesg with pci=nocrs acpi_osi=Linux

https://dl.dropbox.com/u/63420/dmesg2.txt

On Mon, Aug 13, 2012 at 10:13 AM, Athlion <athlion <at> gmail.com> wrote:
> Thanks,
>
> Here is my dmesg from a clean boot:
>
> https://dl.dropbox.com/u/63420/dmesg.txt
>
> Now that I scanned it more thoroughly I found these:
>
> [    0.363136] [Firmware Bug]: ACPI: BIOS _OSI(Linux) query ignored
> and
> [    0.387856] PCI: Using host bridge windows from ACPI; if necessary,
> use "pci=nocrs" and report a bug
>
> my /proc/cmdline is:
> BOOT_IMAGE=/boot/vmlinuz-linux
> root=UUID=44cf687d-4827-4765-8758-98d44a745d07 ro quiet
> resume=/dev/sda2
>
> maybe they indicate a lurking problem?
>
> (in parallel, I will try booting with pci=nocrs and report back)
>
> And there are other people having this issue, some from way back, as
> can be seen here
> https://bbs.archlinux.org/viewtopic.php?id=144381
(Continue reading)

Athlion | 16 Aug 2012 17:01
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

Some new information, if that is helpful at all.

I have managed to circumvent the problem (I am not at 68 hours uptime
with proper suspend/resume by closing the lid) by killing the X server
every now and then (every 10-12 hours). Anyway, this afternoon, my
battery was drained and the system hibernated. On resume I saw this:

Aug 16 17:45:55 localhost kernel: [28755.912618] Uhhuh. NMI received
for unknown reason 3d on CPU 0.
Aug 16 17:45:55 localhost kernel: [28755.912622] Do you have a strange
power saving mode enabled?
Aug 16 17:45:55 localhost kernel: [28755.912623] Dazed and confused,
but trying to continue

Is this maybe related to my problem?

Thanks!

On Mon, Aug 13, 2012 at 10:27 AM, Athlion <athlion <at> gmail.com> wrote:
> And this is the dmesg with pci=nocrs acpi_osi=Linux
>
> https://dl.dropbox.com/u/63420/dmesg2.txt
>
> On Mon, Aug 13, 2012 at 10:13 AM, Athlion <athlion <at> gmail.com> wrote:
>> Thanks,
>>
>> Here is my dmesg from a clean boot:
>>
>> https://dl.dropbox.com/u/63420/dmesg.txt
>>
(Continue reading)

Athlion | 25 Aug 2012 19:31
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

I have managed to track where the kernel stops and generate sort of a backtrace.
The result is this (line numbers against linux-3.4.9)

drivers/tty/vt/vt_ioctl.c:133: wait_event_interruptible
drivers/tty/vt/vt_ioctl.c:1426: vt_waitactive
kernel/power/console.c:19: vt_move_to_console
kernel/power/suspend.c:98: pm_prepare_console
suspend_prepare called

Execution stops at wait_event_interruptible. Any ideas why this might be?

Thanks!

On Thu, Aug 16, 2012 at 6:01 PM, Athlion <athlion <at> gmail.com> wrote:
> Some new information, if that is helpful at all.
>
> I have managed to circumvent the problem (I am not at 68 hours uptime
> with proper suspend/resume by closing the lid) by killing the X server
> every now and then (every 10-12 hours). Anyway, this afternoon, my
> battery was drained and the system hibernated. On resume I saw this:
>
> Aug 16 17:45:55 localhost kernel: [28755.912618] Uhhuh. NMI received
> for unknown reason 3d on CPU 0.
> Aug 16 17:45:55 localhost kernel: [28755.912622] Do you have a strange
> power saving mode enabled?
> Aug 16 17:45:55 localhost kernel: [28755.912623] Dazed and confused,
> but trying to continue
>
> Is this maybe related to my problem?
>
(Continue reading)

Rafael J. Wysocki | 27 Aug 2012 09:28
Picon
Gravatar

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Saturday, August 25, 2012, Athlion wrote:
> I have managed to track where the kernel stops and generate sort of a backtrace.
> The result is this (line numbers against linux-3.4.9)
> 
> drivers/tty/vt/vt_ioctl.c:133: wait_event_interruptible
> drivers/tty/vt/vt_ioctl.c:1426: vt_waitactive
> kernel/power/console.c:19: vt_move_to_console
> kernel/power/suspend.c:98: pm_prepare_console
> suspend_prepare called
> 
> Execution stops at wait_event_interruptible. Any ideas why this might be?

Not at the moment, but this is an important data point.

Thanks a lot for tracing this down!

Rafael

> On Thu, Aug 16, 2012 at 6:01 PM, Athlion <athlion <at> gmail.com> wrote:
> > Some new information, if that is helpful at all.
> >
> > I have managed to circumvent the problem (I am not at 68 hours uptime
> > with proper suspend/resume by closing the lid) by killing the X server
> > every now and then (every 10-12 hours). Anyway, this afternoon, my
> > battery was drained and the system hibernated. On resume I saw this:
> >
> > Aug 16 17:45:55 localhost kernel: [28755.912618] Uhhuh. NMI received
> > for unknown reason 3d on CPU 0.
> > Aug 16 17:45:55 localhost kernel: [28755.912622] Do you have a strange
> > power saving mode enabled?
(Continue reading)

Athlion | 27 Aug 2012 09:59
Picon

Re: Kernel stops at "PM: Preparing system for mem sleep", never makes it to "Freezing user space processes ... "

On Mon, Aug 27, 2012 at 10:28 AM, Rafael J. Wysocki <rjw <at> sisk.pl> wrote:
> On Saturday, August 25, 2012, Athlion wrote:
>> I have managed to track where the kernel stops and generate sort of a backtrace.
>> The result is this (line numbers against linux-3.4.9)
>>
>> drivers/tty/vt/vt_ioctl.c:133: wait_event_interruptible
>> drivers/tty/vt/vt_ioctl.c:1426: vt_waitactive
>> kernel/power/console.c:19: vt_move_to_console
>> kernel/power/suspend.c:98: pm_prepare_console
>> suspend_prepare called
>>
>> Execution stops at wait_event_interruptible. Any ideas why this might be?
>
> Not at the moment, but this is an important data point.
>
> Thanks a lot for tracing this down!
>
> Rafael

Feel free to ask of anything supplementary you might need!
--
To unsubscribe from this list: send the line "unsubscribe linux-acpi" in
the body of a message to majordomo <at> vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html


Gmane