[Pkg-acpi-devel] Bug#865340: acpi: Broken suspend + ACPI errors on boot after upgrading jessie=>stretch
Jan Stolarek
jan.stolarek at ed.ac.uk
Thu Jun 22 08:52:10 UTC 2017
Some more information. I've suspended my machine (using power button, as always) and woke it up
later. It woke up but the screen remained off. After about 15-20 seconds I pressed power button
hoping it will suspend again, but it didn't. Pressed the power button one more time and the
screen turned on. I'm attaching relevant dmesg log, hopefully it sheds some light on what is
going on here.
Janek
--
The University of Edinburgh is a charitable body, registered in
Scotland, with registration number SC005336.
-------------- next part --------------
[ 1247.087720] PM: Syncing filesystems ... done.
[ 1247.226374] PM: Preparing system for sleep (mem)
[ 1247.539107] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 1247.540350] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 1247.541414] PM: Suspending system (mem)
[ 1247.541441] Suspending console(s) (use no_console_suspend to debug)
[ 1247.541629] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[ 1247.546790] sd 0:0:0:0: [sda] Stopping disk
[ 1247.622730] serial 00:08: disabled
[ 1247.622775] i8042 aux 00:07: System wakeup disabled by ACPI
[ 1247.622826] i8042 kbd 00:06: System wakeup enabled by ACPI
[ 1247.622986] ACPI : EC: event blocked
[ 1247.622995] e1000e: EEE TX LPI TIMER: 00000011
[ 1247.881615] PM: suspend of devices complete after 340.066 msecs
[ 1247.901927] PM: late suspend of devices complete after 20.308 msecs
[ 1247.902374] ACPI : EC: interrupt blocked
[ 1247.902581] e1000e 0000:00:1f.6: System wakeup enabled by ACPI
[ 1247.902836] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
[ 1247.942067] PM: noirq suspend of devices complete after 40.137 msecs
[ 1247.942624] ACPI: Preparing to enter system sleep state S3
[ 1247.943239] ACPI : EC: EC stopped
[ 1247.943240] PM: Saving platform NVS memory
[ 1247.943261] Disabling non-boot CPUs ...
[ 1247.944614] smpboot: CPU 1 is now offline
[ 1247.946839] smpboot: CPU 2 is now offline
[ 1247.948990] smpboot: CPU 3 is now offline
[ 1247.949471] Broke affinity for irq 126
[ 1247.949474] Broke affinity for irq 129
[ 1247.950516] smpboot: CPU 4 is now offline
[ 1247.951266] Broke affinity for irq 122
[ 1247.951271] Broke affinity for irq 125
[ 1247.951273] Broke affinity for irq 126
[ 1247.951275] Broke affinity for irq 127
[ 1247.951279] Broke affinity for irq 129
[ 1247.952307] smpboot: CPU 5 is now offline
[ 1247.952765] Broke affinity for irq 16
[ 1247.952771] Broke affinity for irq 122
[ 1247.952774] Broke affinity for irq 123
[ 1247.952779] Broke affinity for irq 125
[ 1247.952781] Broke affinity for irq 126
[ 1247.952784] Broke affinity for irq 127
[ 1247.952788] Broke affinity for irq 129
[ 1247.953830] smpboot: CPU 6 is now offline
[ 1247.954248] Broke affinity for irq 1
[ 1247.954251] Broke affinity for irq 8
[ 1247.954253] Broke affinity for irq 9
[ 1247.954256] Broke affinity for irq 12
[ 1247.954259] Broke affinity for irq 16
[ 1247.954265] Broke affinity for irq 122
[ 1247.954267] Broke affinity for irq 123
[ 1247.954269] Broke affinity for irq 124
[ 1247.954271] Broke affinity for irq 125
[ 1247.954274] Broke affinity for irq 126
[ 1247.954278] Broke affinity for irq 127
[ 1247.954282] Broke affinity for irq 129
[ 1247.954284] Broke affinity for irq 131
[ 1247.955324] smpboot: CPU 7 is now offline
[ 1247.958154] ACPI: Low-level resume complete
[ 1247.958268] ACPI : EC: EC started
[ 1247.958269] PM: Restoring platform NVS memory
[ 1247.958998] Suspended for 147915.139 seconds
[ 1247.959952] Enabling non-boot CPUs ...
[ 1247.959991] x86: Booting SMP configuration:
[ 1247.959991] smpboot: Booting Node 0 Processor 1 APIC 0x2
[ 1247.963376] cache: parent cpu1 should not be sleeping
[ 1247.963544] CPU1 is up
[ 1247.963569] smpboot: Booting Node 0 Processor 2 APIC 0x4
[ 1247.966862] cache: parent cpu2 should not be sleeping
[ 1247.967010] CPU2 is up
[ 1247.967035] smpboot: Booting Node 0 Processor 3 APIC 0x6
[ 1247.970328] cache: parent cpu3 should not be sleeping
[ 1247.970479] CPU3 is up
[ 1247.970503] smpboot: Booting Node 0 Processor 4 APIC 0x1
[ 1247.973096] cache: parent cpu4 should not be sleeping
[ 1247.973261] CPU4 is up
[ 1247.973287] smpboot: Booting Node 0 Processor 5 APIC 0x3
[ 1247.975717] cache: parent cpu5 should not be sleeping
[ 1247.975880] CPU5 is up
[ 1247.975905] smpboot: Booting Node 0 Processor 6 APIC 0x5
[ 1247.978420] cache: parent cpu6 should not be sleeping
[ 1247.978588] CPU6 is up
[ 1247.978613] smpboot: Booting Node 0 Processor 7 APIC 0x7
[ 1247.981132] cache: parent cpu7 should not be sleeping
[ 1247.981321] CPU7 is up
[ 1247.986987] ACPI: Waking up from system sleep state S3
[ 1247.988135] acpi LNXPOWER:16: Turning OFF
[ 1247.988155] acpi LNXPOWER:15: Turning OFF
[ 1247.988174] acpi LNXPOWER:14: Turning OFF
[ 1247.988194] acpi LNXPOWER:13: Turning OFF
[ 1247.988214] acpi LNXPOWER:12: Turning OFF
[ 1247.988233] acpi LNXPOWER:11: Turning OFF
[ 1247.988253] acpi LNXPOWER:10: Turning OFF
[ 1247.988273] acpi LNXPOWER:0f: Turning OFF
[ 1247.988293] acpi LNXPOWER:0e: Turning OFF
[ 1247.988313] acpi LNXPOWER:0d: Turning OFF
[ 1247.988332] acpi LNXPOWER:0c: Turning OFF
[ 1247.988352] acpi LNXPOWER:0b: Turning OFF
[ 1247.988372] acpi LNXPOWER:0a: Turning OFF
[ 1247.988391] acpi LNXPOWER:09: Turning OFF
[ 1247.988411] acpi LNXPOWER:08: Turning OFF
[ 1247.988430] acpi LNXPOWER:07: Turning OFF
[ 1247.988450] acpi LNXPOWER:06: Turning OFF
[ 1247.988470] acpi LNXPOWER:05: Turning OFF
[ 1247.988489] acpi LNXPOWER:04: Turning OFF
[ 1247.988509] acpi LNXPOWER:03: Turning OFF
[ 1247.988630] ACPI : EC: interrupt unblocked
[ 1248.005370] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
[ 1248.005466] PM: noirq resume of devices complete after 16.942 msecs
[ 1248.015600] PM: early resume of devices complete after 10.115 msecs
[ 1248.015645] ACPI : EC: event unblocked
[ 1248.015679] rtc_cmos 00:04: System wakeup disabled by ACPI
[ 1248.015788] e1000e 0000:00:1f.6: System wakeup disabled by ACPI
[ 1248.015893] i8042 kbd 00:06: System wakeup disabled by ACPI
[ 1248.016147] sd 0:0:0:0: [sda] Starting disk
[ 1248.016726] [drm] GuC firmware load skipped
[ 1248.017389] serial 00:08: activated
[ 1248.375954] ata2: SATA link down (SStatus 4 SControl 300)
[ 1248.376248] ata4: SATA link down (SStatus 4 SControl 300)
[ 1248.376265] ata3: SATA link down (SStatus 4 SControl 300)
[ 1248.376338] ata6: SATA link down (SStatus 4 SControl 300)
[ 1249.833524] [drm] RC6 on
[ 1252.001305] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 1269.013180] INFO: rcu_sched self-detected stall on CPU
[ 1269.013182] 6-...: (5249 ticks this GP) idle=961/140000000000001/0 softirq=13250/13250 fqs=2624
[ 1269.013183] (t=5250 jiffies g=26710 c=26709 q=130)
[ 1269.013184] Task dump for CPU 6:
[ 1269.013185] kworker/u16:45 R running task 0 2334 2 0x00000008
[ 1269.013188] Workqueue: events_unbound async_run_entry_fn
[ 1269.013190] ffffffffbeb13580 ffffffffbdea3bbb 0000000000000006 ffffffffbeb13580
[ 1269.013190] ffffffffbdf7a4a6 ffff98653f598fc0 ffffffffbea4a6c0 0000000000000000
[ 1269.013191] ffffffffbeb13580 00000000ffffffff ffffffffbdededf4 0000000000d0027f
[ 1269.013191] Call Trace:
[ 1269.013194] <IRQ>
[ 1269.013194] [<ffffffffbdea3bbb>] ? sched_show_task+0xcb/0x130
[ 1269.013195] [<ffffffffbdf7a4a6>] ? rcu_dump_cpu_stacks+0x92/0xb2
[ 1269.013214] [<ffffffffbdededf4>] ? rcu_check_callbacks+0x754/0x8a0
[ 1269.013215] [<ffffffffbdeed0b3>] ? update_wall_time+0x473/0x790
[ 1269.013216] [<ffffffffbdef48b0>] ? tick_sched_handle.isra.12+0x50/0x50
[ 1269.013217] [<ffffffffbdee5708>] ? update_process_times+0x28/0x50
[ 1269.013218] [<ffffffffbdef4880>] ? tick_sched_handle.isra.12+0x20/0x50
[ 1269.013219] [<ffffffffbdef48e8>] ? tick_sched_timer+0x38/0x70
[ 1269.013219] [<ffffffffbdee60ec>] ? __hrtimer_run_queues+0xdc/0x240
[ 1269.013220] [<ffffffffbdee67bc>] ? hrtimer_interrupt+0x9c/0x1a0
[ 1269.013221] [<ffffffffbe408ba9>] ? smp_apic_timer_interrupt+0x39/0x50
[ 1269.013236] [<ffffffffbe407ec2>] ? apic_timer_interrupt+0x82/0x90
[ 1269.013312] <EOI>
[ 1269.013312] [<ffffffffc0ad6410>] ? nv_rdtsc+0x170/0x270 [nvidia]
[ 1269.013369] [<ffffffffc0ad634c>] ? nv_rdtsc+0xac/0x270 [nvidia]
[ 1269.013423] [<ffffffffc0ad639e>] ? nv_rdtsc+0xfe/0x270 [nvidia]
[ 1269.013476] [<ffffffffc0ad6b18>] ? _nv000893rm+0x78/0xb0 [nvidia]
[ 1269.013530] [<ffffffffc0ad6904>] ? _nv016774rm+0x164/0x220 [nvidia]
[ 1269.013584] [<ffffffffc0abdb7d>] ? _nv017526rm+0x4d/0x140 [nvidia]
[ 1269.013639] [<ffffffffc0ac23f2>] ? _nv000833rm+0x392/0x470 [nvidia]
[ 1269.013694] [<ffffffffc0ac26f0>] ? _nv000750rm+0x220/0x3c0 [nvidia]
[ 1269.013748] [<ffffffffc0ac13db>] ? _nv000825rm+0x1bb/0x200 [nvidia]
[ 1269.013803] [<ffffffffc0ac5cc0>] ? rm_power_management+0x110/0x150 [nvidia]
[ 1269.013835] [<ffffffffc051109d>] ? nv_power_management+0x1ad/0x280 [nvidia]
[ 1269.013836] [<ffffffffbe177470>] ? pci_pm_thaw+0x90/0x90
[ 1269.013868] [<ffffffffc0514421>] ? nvidia_resume+0x31/0x80 [nvidia]
[ 1269.013870] [<ffffffffbe281a07>] ? dpm_run_callback+0x47/0x110
[ 1269.013871] [<ffffffffbe281e42>] ? device_resume+0x82/0x190
[ 1269.013871] [<ffffffffbe281f69>] ? async_resume+0x19/0x40
[ 1269.013872] [<ffffffffbde994c4>] ? async_run_entry_fn+0x34/0x140
[ 1269.013873] [<ffffffffbde90374>] ? process_one_work+0x184/0x410
[ 1269.013873] [<ffffffffbde9064d>] ? worker_thread+0x4d/0x480
[ 1269.013874] [<ffffffffbde90600>] ? process_one_work+0x410/0x410
[ 1269.013875] [<ffffffffbde965c7>] ? kthread+0xd7/0xf0
[ 1269.013876] [<ffffffffbde964f0>] ? kthread_park+0x60/0x60
[ 1269.013877] [<ffffffffbe4064f5>] ? ret_from_fork+0x25/0x30
[ 1270.761230] INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 6-... } 5658 jiffies s: 127 root: 0x40/.
[ 1270.761230] blocking rcu_node structures:
[ 1270.761231] Task dump for CPU 6:
[ 1270.761232] kworker/u16:45 R running task 0 2334 2 0x00000008
[ 1270.761233] Workqueue: events_unbound async_run_entry_fn
[ 1270.761234] 000000000000c000 ffff9864ed7bef78 ffff9864ed7befc0 ffffffffc0ad6410
[ 1270.761235] 0000000000000000 00000000000c490f 00000000000c490f 0000000000009400
[ 1270.761236] 0000000000000001 0000000000003008 0000000000009400 ffffffffc0ad639e
[ 1270.761236] Call Trace:
[ 1270.761306] [<ffffffffc0ad6410>] ? nv_rdtsc+0x170/0x270 [nvidia]
[ 1270.761361] [<ffffffffc0ad639e>] ? nv_rdtsc+0xfe/0x270 [nvidia]
[ 1270.761414] [<ffffffffc0ad639e>] ? nv_rdtsc+0xfe/0x270 [nvidia]
[ 1270.761468] [<ffffffffc0ad6be9>] ? _nv010018rm+0x29/0x40 [nvidia]
[ 1270.761521] [<ffffffffc0ad641d>] ? nv_rdtsc+0x17d/0x270 [nvidia]
[ 1270.761575] [<ffffffffc0adfd5a>] ? _nv022666rm+0x84da/0xbd60 [nvidia]
[ 1270.761628] [<ffffffffc0ad6b25>] ? _nv000893rm+0x85/0xb0 [nvidia]
[ 1270.761682] [<ffffffffc0ad6904>] ? _nv016774rm+0x164/0x220 [nvidia]
[ 1270.761737] [<ffffffffc0abdb7d>] ? _nv017526rm+0x4d/0x140 [nvidia]
[ 1270.761791] [<ffffffffc0ac23f2>] ? _nv000833rm+0x392/0x470 [nvidia]
[ 1270.761845] [<ffffffffc0ac26f0>] ? _nv000750rm+0x220/0x3c0 [nvidia]
[ 1270.761899] [<ffffffffc0ac13db>] ? _nv000825rm+0x1bb/0x200 [nvidia]
[ 1270.761953] [<ffffffffc0ac5cc0>] ? rm_power_management+0x110/0x150 [nvidia]
[ 1270.761985] [<ffffffffc051109d>] ? nv_power_management+0x1ad/0x280 [nvidia]
[ 1270.761986] [<ffffffffbe177470>] ? pci_pm_thaw+0x90/0x90
[ 1270.762019] [<ffffffffc0514421>] ? nvidia_resume+0x31/0x80 [nvidia]
[ 1270.762020] [<ffffffffbe281a07>] ? dpm_run_callback+0x47/0x110
[ 1270.762021] [<ffffffffbe281e42>] ? device_resume+0x82/0x190
[ 1270.762022] [<ffffffffbe281f69>] ? async_resume+0x19/0x40
[ 1270.762022] [<ffffffffbde994c4>] ? async_run_entry_fn+0x34/0x140
[ 1270.762023] [<ffffffffbde90374>] ? process_one_work+0x184/0x410
[ 1270.762024] [<ffffffffbde9064d>] ? worker_thread+0x4d/0x480
[ 1270.762024] [<ffffffffbde90600>] ? process_one_work+0x410/0x410
[ 1270.762025] [<ffffffffbde965c7>] ? kthread+0xd7/0xf0
[ 1270.762026] [<ffffffffbde964f0>] ? kthread_park+0x60/0x60
[ 1270.762027] [<ffffffffbe4064f5>] ? ret_from_fork+0x25/0x30
[ 1282.149750] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[ 1282.156160] ACPI Error: Needed [Buffer/String/Package], found [Integer] ffff98652c459ea0 (20160831/exresop-594)
[ 1282.156161] ACPI Exception: AE_AML_OPERAND_TYPE, While resolving operands for [OpcodeName unavailable] (20160831/dswexec-461)
[ 1282.156165] ACPI Error: Method parse/execution failed [\_SB.WMIV.WVPO] (Node ffff98652e8a7aa0), AE_AML_OPERAND_TYPE (20160831/psparse-543)
[ 1282.156226] ACPI Error: Method parse/execution failed [\_SB.WMIV.WMPV] (Node ffff98652e8a74b0), AE_AML_OPERAND_TYPE (20160831/psparse-543)
[ 1282.158449] ACPI Error: Needed [Buffer/String/Package], found [Integer] ffff986516b9b4c8 (20160831/exresop-594)
[ 1282.158450] ACPI Exception: AE_AML_OPERAND_TYPE, While resolving operands for [OpcodeName unavailable] (20160831/dswexec-461)
[ 1282.158453] ACPI Error: Method parse/execution failed [\_SB.WMIV.WVPO] (Node ffff98652e8a7aa0), AE_AML_OPERAND_TYPE (20160831/psparse-543)
[ 1282.158456] ata1.00: ACPI cmd f5/00:00:00:00:00:e0 (SECURITY FREEZE LOCK) filtered out
[ 1282.158457] ACPI Error: Method parse/execution failed [\_SB.WMIV.WMPV] (Node ffff98652e8a74b0), AE_AML_OPERAND_TYPE (20160831/psparse-543)
[ 1282.160219] ata1.00: ACPI cmd f5/00:00:00:00:00:e0 (SECURITY FREEZE LOCK) filtered out
[ 1282.160408] ata1.00: configured for UDMA/100
[ 1282.205918] PM: resume of devices complete after 34190.272 msecs
[ 1282.206357] PM: Finishing wakeup.
[ 1282.206357] Restarting tasks ... done.
[ 1282.212898] video LNXVIDEO:00: Restoring backlight state
[ 1282.212899] video LNXVIDEO:01: Restoring backlight state
More information about the Pkg-acpi-devel
mailing list