Re: 4.3-rc2 on radeon: new backtraces during resume

From: Pavel Machek
Date: Thu Sep 24 2015 - 08:00:14 EST


On Wed 2015-09-23 11:26:18, Alex Deucher wrote:
> On Wed, Sep 23, 2015 at 7:51 AM, Pavel Machek <pavel@xxxxxx> wrote:
> > HI!
> >
> >
> > I suspended T40p by mistake, and I got some lovely backtraces as a
> > result:
> >
> > Any ideas?
>
> Please see this thread:
> https://lkml.org/lkml/2015/9/23/361

Yes, patch from that thread helped. Thanks!
Pavel


> > [ 0.000000] Initializing cgroup subsys cpu
> > [ 0.000000] Linux version 4.3.0-rc2+ (pavel@hobit) (gcc version 4.9.2 (Debian 4.9.2-10) ) #111 SMP Wed Sep 23 13:29:04 CEST 2015
> > ...
> > [ 855.275406] PM: Syncing filesystems ... done.
> > [ 855.745355] PM: Preparing system for sleep (mem)
> > [ 855.830116] Freezing user space processes ... (elapsed 0.010 seconds) done.
> > [ 855.841061] Freezing remaining freezable tasks ... (elapsed 0.003 seconds) done.
> > [ 855.844739] PM: Suspending system (mem)
> > [ 855.844809] Suspending console(s) (use no_console_suspend to debug)
> > [ 856.054406] parport_pc 00:07: disabled
> > [ 856.055141] serial 00:06: disabled
> > [ 856.056458] serial 00:06: System wakeup disabled by ACPI
> > [ 856.058401] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> > [ 856.059365] ------------[ cut here ]------------
> > [ 856.059381] WARNING: CPU: 0 PID: 6609 at include/drm/drm_crtc.h:1577 drm_helper_choose_encoder_dpms+0x82/0x90()
> > [ 856.059384] Modules linked in:
> > [ 856.059391] CPU: 0 PID: 6609 Comm: kworker/u2:7 Not tainted 4.3.0-rc2+ #111
> > [ 856.059393] Hardware name: IBM 2373G3U/2373G3U, BIOS 1RETDNWW (3.19 ) 10/13/2005
> > [ 856.059402] Workqueue: events_unbound async_run_entry_fn
> > [ 856.059416] 00000000 00000000 de099d94 c42b40a8 00000000 de099db0 c403ecdb 00000629
> > [ 856.059427] c438fd82 f6acd800 f585ee00 00000003 de099dc0 c403ed7f 00000009 00000000
> > [ 856.059437] de099dd0 c438fd82 f585ee00 f6000000 de099df0 c4390132 f6acd800 00000000
> > [ 856.059439] Call Trace:
> > [ 856.059450] [<c42b40a8>] dump_stack+0x41/0x59
> > [ 856.059457] [<c403ecdb>] warn_slowpath_common+0x6b/0xa0
> > [ 856.059462] [<c438fd82>] ? drm_helper_choose_encoder_dpms+0x82/0x90
> > [ 856.059467] [<c403ed7f>] warn_slowpath_null+0xf/0x20
> > [ 856.059472] [<c438fd82>] drm_helper_choose_encoder_dpms+0x82/0x90
> > [ 856.059477] [<c4390132>] drm_helper_connector_dpms+0x32/0xf0
> > [ 856.059485] [<c43c6d14>] radeon_suspend_kms+0x64/0x350
> > [ 856.059491] [<c43c4958>] radeon_pmops_suspend+0x18/0x20
> > [ 856.059497] [<c42e311d>] pci_pm_suspend+0x5d/0x130
> > [ 856.059502] [<c42e30c0>] ? pci_pm_freeze+0xc0/0xc0
> > [ 856.059509] [<c4567b20>] dpm_run_callback+0x30/0x70
> > [ 856.059514] [<c4568432>] __device_suspend+0xd2/0x290
> > [ 856.059522] [<c407d971>] ? __lock_acquire.isra.24+0x3b1/0xca0
> > [ 856.059526] [<c4568607>] async_suspend+0x17/0x90
> > [ 856.059531] [<c4059caf>] async_run_entry_fn+0x4f/0x140
> > [ 856.059537] [<c40525df>] process_one_work+0x15f/0x3a0
> > [ 856.059542] [<c40525df>] ? process_one_work+0x15f/0x3a0
> > [ 856.059546] [<c4052589>] ? process_one_work+0x109/0x3a0
> > [ 856.059551] [<c4052859>] worker_thread+0x39/0x430
> > [ 856.059556] [<c4052820>] ? process_one_work+0x3a0/0x3a0
> > [ 856.059562] [<c4057aae>] kthread+0xae/0xd0
> > [ 856.059572] [<c49c64c1>] ret_from_kernel_thread+0x21/0x30
> > [ 856.059577] [<c4057a00>] ? kthread_create_on_node+0x170/0x170
> > [ 856.059581] ---[ end trace c98a514a441969f1 ]---
> > [ 856.079439] ------------[ cut here ]------------
> > [ 856.079446] WARNING: CPU: 0 PID: 6609 at include/drm/drm_crtc.h:1577 drm_helper_choose_crtc_dpms+0x82/0x90()
> > [ 856.079449] Modules linked in:
> > [ 856.079454] CPU: 0 PID: 6609 Comm: kworker/u2:7 Tainted: G W 4.3.0-rc2+ #111
> > [ 856.079457] Hardware name: IBM 2373G3U/2373G3U, BIOS 1RETDNWW (3.19 ) 10/13/2005
> > [ 856.079462] Workqueue: events_unbound async_run_entry_fn
> > [ 856.079473] 00000000 00000000 de099d94 c42b40a8 00000000 de099db0 c403ecdb 00000629
> > [ 856.079484] c438fe12 f6000000 f6acd800 00000003 de099dc0 c403ed7f 00000009 00000000
> > [ 856.079495] de099dd0 c438fe12 c43e24c0 f6000000 de099df0 c43901d6 f6acd800 00000000
> > [ 856.079496] Call Trace:
> > [ 856.079503] [<c42b40a8>] dump_stack+0x41/0x59
> > [ 856.079508] [<c403ecdb>] warn_slowpath_common+0x6b/0xa0
> > [ 856.079512] [<c438fe12>] ? drm_helper_choose_crtc_dpms+0x82/0x90
> > [ 856.079517] [<c403ed7f>] warn_slowpath_null+0xf/0x20
> > [ 856.079522] [<c438fe12>] drm_helper_choose_crtc_dpms+0x82/0x90
> > [ 856.079529] [<c43e24c0>] ? radeon_crtc_mode_fixup+0x10/0x10
> > [ 856.079534] [<c43901d6>] drm_helper_connector_dpms+0xd6/0xf0
> > [ 856.079539] [<c43c6d14>] radeon_suspend_kms+0x64/0x350
> > [ 856.079544] [<c43c4958>] radeon_pmops_suspend+0x18/0x20
> > [ 856.079549] [<c42e311d>] pci_pm_suspend+0x5d/0x130
> > [ 856.079554] [<c42e30c0>] ? pci_pm_freeze+0xc0/0xc0
> > [ 856.079558] [<c4567b20>] dpm_run_callback+0x30/0x70
> > [ 856.079563] [<c4568432>] __device_suspend+0xd2/0x290
> > [ 856.079568] [<c407d971>] ? __lock_acquire.isra.24+0x3b1/0xca0
> > [ 856.079573] [<c4568607>] async_suspend+0x17/0x90
> > [ 856.079578] [<c4059caf>] async_run_entry_fn+0x4f/0x140
> > [ 856.079583] [<c40525df>] process_one_work+0x15f/0x3a0
> > [ 856.079587] [<c40525df>] ? process_one_work+0x15f/0x3a0
> > [ 856.079592] [<c4052589>] ? process_one_work+0x109/0x3a0
> > [ 856.079597] [<c4052859>] worker_thread+0x39/0x430
> > [ 856.079601] [<c4052820>] ? process_one_work+0x3a0/0x3a0
> > [ 856.079606] [<c4057aae>] kthread+0xae/0xd0
> > [ 856.079613] [<c49c64c1>] ret_from_kernel_thread+0x21/0x30
> > [ 856.079619] [<c4057a00>] ? kthread_create_on_node+0x170/0x170
> > [ 856.079622] ---[ end trace c98a514a441969f2 ]---
> > [ 856.139794] sd 0:0:0:0: [sda] Stopping disk
> > [ 856.160253] radeon 0000:01:00.0: Refused to change power state, currently in D0
> > [ 856.579987] PM: suspend of devices complete after 732.935 msecs
> > [ 856.579992] PM: suspend devices took 0.732 seconds
> > [ 856.584622] PM: late suspend of devices complete after 4.621 msecs
> > [ 856.589038] pci0000:00: System wakeup enabled by ACPI
> > [ 856.589427] uhci_hcd 0000:00:1d.1: System wakeup enabled by ACPI
> > [ 856.628193] uhci_hcd 0000:00:1d.0: System wakeup enabled by ACPI
> > [ 856.628276] PM: noirq suspend of devices complete after 43.644 msecs
> > [ 856.628556] ACPI: Preparing to enter system sleep state S3
> > [ 856.820755] ACPI : EC: EC stopped
> > [ 856.820758] PM: Saving platform NVS memory
> > [ 856.820805] Disabling non-boot CPUs ...
> > [ 856.820805] ACPI: Low-level resume complete
> > [ 856.820805] ACPI : EC: EC started
> > [ 856.820805] PM: Restoring platform NVS memory
> > [ 856.820967] ACPI: Waking up from system sleep state S3
> > [ 857.208208] uhci_hcd 0000:00:1d.0: System wakeup disabled by ACPI
> > [ 857.208429] uhci_hcd 0000:00:1d.1: System wakeup disabled by ACPI
> > [ 857.208522] pci0000:00: System wakeup disabled by ACPI
> > [ 857.209245] PM: noirq resume of devices complete after 40.983 msecs
> > [ 857.215741] PM: early resume of devices complete after 4.255 msecs
> > [ 857.216870] usb usb2: root hub lost power or was reset
> > [ 857.216940] usb usb3: root hub lost power or was reset
> > [ 857.217006] usb usb4: root hub lost power or was reset
> > [ 857.217265] [drm] AGP mode requested: 1
> > [ 857.217271] agpgart-intel 0000:00:00.0: AGP 2.0 bridge
> > [ 857.217315] agpgart-intel 0000:00:00.0: putting AGP V2 device into 1x mode
> > [ 857.217406] radeon 0000:01:00.0: putting AGP V2 device into 1x mode
> > [ 857.217463] radeon 0000:01:00.0: GTT: 256M 0xD0000000 - 0xDFFFFFFF
> > [ 857.239072] radeon 0000:01:00.0: WB disabled
> > [ 857.239080] radeon 0000:01:00.0: fence driver on ring 0 use gpu addr 0x00000000d0000000 and cpu addr 0xf841a000
> > [ 857.239127] [drm] radeon: ring at 0x00000000D0001000
> > [ 857.239155] [drm] ring test succeeded in 0 usecs
> > [ 857.239235] [drm] ib test succeeded in 0 usecs
> > [ 857.340074] ------------[ cut here ]------------
> > [ 857.340090] WARNING: CPU: 0 PID: 6612 at include/drm/drm_crtc.h:1577 drm_helper_choose_encoder_dpms+0x82/0x90()
> > [ 857.340094] Modules linked in:
> > [ 857.340100] CPU: 0 PID: 6612 Comm: kworker/u2:10 Tainted: G W 4.3.0-rc2+ #111
> > [ 857.340103] Hardware name: IBM 2373G3U/2373G3U, BIOS 1RETDNWW (3.19 ) 10/13/2005
> > [ 857.340111] Workqueue: events_unbound async_run_entry_fn
> > [ 857.340123] 00000000 00000000 de161dac c42b40a8 00000000 de161dc8 c403ecdb 00000629
> > [ 857.340132] c438fd82 f6acd800 f585ee00 00000000 de161dd8 c403ed7f 00000009 00000000
> > [ 857.340141] de161de8 c438fd82 f585ee00 f6000000 de161e08 c4390132 c4390811 00000003
> > [ 857.340143] Call Trace:
> > [ 857.340154] [<c42b40a8>] dump_stack+0x41/0x59
> > [ 857.340161] [<c403ecdb>] warn_slowpath_common+0x6b/0xa0
> > [ 857.340166] [<c438fd82>] ? drm_helper_choose_encoder_dpms+0x82/0x90
> > [ 857.340171] [<c403ed7f>] warn_slowpath_null+0xf/0x20
> > [ 857.340176] [<c438fd82>] drm_helper_choose_encoder_dpms+0x82/0x90
> > [ 857.340181] [<c4390132>] drm_helper_connector_dpms+0x32/0xf0
> > [ 857.340186] [<c4390811>] ? drm_helper_resume_force_mode+0x101/0x140
> > [ 857.340193] [<c43c7259>] radeon_resume_kms+0x259/0x380
> > [ 857.340198] [<c43c4898>] radeon_pmops_resume+0x18/0x20
> > [ 857.340204] [<c42e2eea>] pci_pm_resume+0x4a/0x90
> > [ 857.340208] [<c42e2ea0>] ? pci_pm_thaw+0x80/0x80
> > [ 857.340215] [<c4567b20>] dpm_run_callback+0x30/0x70
> > [ 857.340220] [<c4567e76>] device_resume+0x76/0x160
> > [ 857.340224] [<c4567f76>] async_resume+0x16/0x40
> > [ 857.340229] [<c4059caf>] async_run_entry_fn+0x4f/0x140
> > [ 857.340235] [<c40525df>] process_one_work+0x15f/0x3a0
> > [ 857.340239] [<c40525df>] ? process_one_work+0x15f/0x3a0
> > [ 857.340243] [<c4052589>] ? process_one_work+0x109/0x3a0
> > [ 857.340248] [<c4052859>] worker_thread+0x39/0x430
> > [ 857.340252] [<c4052820>] ? process_one_work+0x3a0/0x3a0
> > [ 857.340259] [<c4057aae>] kthread+0xae/0xd0
> > [ 857.340268] [<c49c64c1>] ret_from_kernel_thread+0x21/0x30
> > [ 857.340273] [<c4057a00>] ? kthread_create_on_node+0x170/0x170
> > [ 857.340277] ---[ end trace c98a514a441969f3 ]---
> > [ 857.340279] ------------[ cut here ]------------
> > [ 857.340285] WARNING: CPU: 0 PID: 6612 at include/drm/drm_crtc.h:1577 drm_helper_choose_crtc_dpms+0x82/0x90()
> > [ 857.340287] Modules linked in:
> > [ 857.340292] CPU: 0 PID: 6612 Comm: kworker/u2:10 Tainted: G W 4.3.0-rc2+ #111
> > [ 857.340294] Hardware name: IBM 2373G3U/2373G3U, BIOS 1RETDNWW (3.19 ) 10/13/2005
> > [ 857.340299] Workqueue: events_unbound async_run_entry_fn
> > [ 857.340308] 00000000 00000000 de161dac c42b40a8 00000000 de161dc8 c403ecdb 00000629
> > [ 857.340317] c438fe12 f6000000 f6acd800 00000000 de161dd8 c403ed7f 00000009 00000000
> > [ 857.340327] de161de8 c438fe12 f585ee00 f6000000 de161e08 c4390159 00000003 c43e24c0
> > [ 857.340328] Call Trace:
> > [ 857.340334] [<c42b40a8>] dump_stack+0x41/0x59
> > [ 857.340338] [<c403ecdb>] warn_slowpath_common+0x6b/0xa0
> > [ 857.340343] [<c438fe12>] ? drm_helper_choose_crtc_dpms+0x82/0x90
> > [ 857.340348] [<c403ed7f>] warn_slowpath_null+0xf/0x20
> > [ 857.340353] [<c438fe12>] drm_helper_choose_crtc_dpms+0x82/0x90
> > [ 857.340357] [<c4390159>] drm_helper_connector_dpms+0x59/0xf0
> > [ 857.340364] [<c43e24c0>] ? radeon_crtc_mode_fixup+0x10/0x10
> > [ 857.340369] [<c43c7259>] radeon_resume_kms+0x259/0x380
> > [ 857.340374] [<c43c4898>] radeon_pmops_resume+0x18/0x20
> > [ 857.340378] [<c42e2eea>] pci_pm_resume+0x4a/0x90
> > [ 857.340382] [<c42e2ea0>] ? pci_pm_thaw+0x80/0x80
> > [ 857.340387] [<c4567b20>] dpm_run_callback+0x30/0x70
> > [ 857.340391] [<c4567e76>] device_resume+0x76/0x160
> > [ 857.340396] [<c4567f76>] async_resume+0x16/0x40
> > [ 857.340400] [<c4059caf>] async_run_entry_fn+0x4f/0x140
> > [ 857.340405] [<c40525df>] process_one_work+0x15f/0x3a0
> > [ 857.340409] [<c40525df>] ? process_one_work+0x15f/0x3a0
> > [ 857.340413] [<c4052589>] ? process_one_work+0x109/0x3a0
> > [ 857.340418] [<c4052859>] worker_thread+0x39/0x430
> > [ 857.340423] [<c4052820>] ? process_one_work+0x3a0/0x3a0
> > [ 857.340428] [<c4057aae>] kthread+0xae/0xd0
> > [ 857.340434] [<c49c64c1>] ret_from_kernel_thread+0x21/0x30
> > [ 857.340440] [<c4057a00>] ? kthread_create_on_node+0x170/0x170
> > [ 857.340443] ---[ end trace c98a514a441969f4 ]---
> > [ 857.398761] rtc_cmos 00:02: System wakeup disabled by ACPI
> > [ 857.401294] serial 00:06: activated
> > [ 857.404233] parport_pc 00:07: activated
> > [ 857.411941] sd 0:0:0:0: [sda] Starting disk
> > [ 857.572518] ata2.00: ACPI cmd ef/03:42:00:00:00:a0 (SET FEATURES) filtered out
> > [ 857.572525] ata2.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
> > [ 857.572734] ata2.00: ACPI cmd e3/00:1f:00:00:00:a0 (IDLE) succeeded
> > [ 857.573004] ata2.00: ACPI cmd e3/00:02:00:00:00:a0 (IDLE) succeeded
> > [ 857.588619] ata2.00: configured for UDMA/33
> > [ 857.732100] usb 4-1: reset full-speed USB device number 2 using uhci_hcd
> > [ 859.180837] ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
> > [ 859.180845] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
> > [ 859.180851] ata1.00: ACPI cmd ef/03:45:00:00:00:a0 (SET FEATURES) filtered out
> > [ 859.180857] ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
> > [ 859.196408] ata1.00: configured for UDMA/100
> > [ 859.503865] PM: resume of devices complete after 2288.111 msecs
> > [ 859.507054] PM: resume devices took 2.292 seconds
> > [ 860.666467] PM: Finishing wakeup.
> > [ 860.666470] Restarting tasks ... done.
> > [ 861.181229] ath5k: hacked with 20msec max.. 15, 15
> > [ 861.181251] ath5k: hacked with 20msec max.. 15, 15
> > [ 861.181267] ath5k: hacked with 20msec max.. 15, 15
> > [ 861.181283] ath5k: hacked with 20msec max.. 15, 15
> > [ 865.922799] wlan1: authenticate with 00:11:95:05:30:d7
> > [ 865.945256] wlan1: send auth to 00:11:95:05:30:d7 (try 1/3)
> > [ 865.948705] wlan1: authenticated
> > [ 865.953024] ath5k 0000:02:02.0 wlan1: disabling HT as WMM/QoS is not supported by the AP
> > [ 865.953037] ath5k 0000:02:02.0 wlan1: disabling VHT as WMM/QoS is not supported by the AP
> > [ 865.956187] wlan1: associate with 00:11:95:05:30:d7 (try 1/3)
> > [ 865.958619] wlan1: RX AssocResp from 00:11:95:05:30:d7 (capab=0x401 status=0 aid=5)
> > [ 865.958669] ath5k: hacked with 20msec max.. 15, 15
> > [ 865.958690] ath5k: hacked with 20msec max.. 15, 15
> > [ 865.958710] ath5k: hacked with 20msec max.. 15, 15
> > [ 865.958728] ath5k: hacked with 20msec max.. 15, 15
> > [ 865.958814] wlan1: associated
> > [ 869.753870] ath5k: ath5k_hw_get_isr: ISR: 0x00000400 IMR: 0x80081035
> > [ 871.955532] ath5k: ath5k_hw_get_isr: ISR: 0x00000400 IMR: 0x80081035
> > [ 873.952628] ath5k: ath5k_hw_get_isr: ISR: 0x00000400 IMR: 0x80081035
> >
> >
> >
> > --
> > (english) http://www.livejournal.com/~pavelmachek
> > (cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
> > _______________________________________________
> > dri-devel mailing list
> > dri-devel@xxxxxxxxxxxxxxxxxxxxx
> > http://lists.freedesktop.org/mailman/listinfo/dri-devel

--
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/