Created attachment 101324 [details]
Xorg log

Imre, any ideas?

Patrik, could you reproduce the issue and provide a dmesg log with drm.debug=14 kernel parameter set?

I've since upgraded to 3.16.0 and turned on drm.debug and I think I have the same problem but the stack differs.

I intend to upgrade to the latest 3.17 RC next time I reboot.

I've concatenated /var/log/dmesg and dmesg. Let me know if you want the missing pieces from kern.log.



[223879.226074] ------------[ cut here ]------------
[223879.226097] WARNING: CPU: 3 PID: 16664 at /home/apw/COD/linux/drivers/gpu/drm/i915/intel_pm.c:6001 intel_disp
lay_power_put+0x11a/0x160 [i915]()
[223879.226117] Modules linked in: uas usb_storage btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs x
fs libcrc32c ctr ccm arc4 intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm joydev serio_ra
w iwlmvm mac80211 rfcomm iwlwifi bnep btusb snd_hda_codec_realtek rtsx_pci_ms snd_hda_codec_hdmi snd_hda_codec_ge
neric bluetooth cfg80211 memstick 6lowpan_iphc snd_hda_intel snd_hda_controller snd_hda_codec thinkpad_acpi snd_h
wdep snd_pcm nvram snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq mac_hid intel_smartconnect snd_seq_device 
snd_timer binfmt_misc snd lpc_ich soundcore parport_pc nls_iso8859_1 ppdev lp parport sch_fq dm_crypt rtsx_pci_sd
mmc crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 i915 lrw gf128mul glue_helper ablk_h
elper cryptd psmouse
[223879.226121]  e1000e i2c_algo_bit drm_kms_helper ahci drm libahci ptp rtsx_pci pps_core wmi video [last unload
ed: ipmi_msghandler]
[223879.226123] CPU: 3 PID: 16664 Comm: kworker/u16:34 Tainted: G        W     3.16.0-031600-generic #20140803193
5
[223879.226124] Hardware name: LENOVO 20AM009DMS/20AM009DMS, BIOS GIET75WW (2.25 ) 06/24/2014
[223879.226127] Workqueue: events_unbound async_run_entry_fn
[223879.226129]  0000000000001771 ffff88002becfa48 ffffffff82786525 ffffffff82c51ad8
[223879.226130]  0000000000000000 ffff88002becfa88 ffffffff8207207c ffff88002becfa68
[223879.226131]  0000000000000000 ffffffffc037d5e0 ffff88022ab40000 0000000000800000
[223879.226131] Call Trace:
[223879.226135]  [<ffffffff82786525>] dump_stack+0x46/0x58
[223879.226138]  [<ffffffff8207207c>] warn_slowpath_common+0x8c/0xc0
[223879.226140]  [<ffffffff820720ca>] warn_slowpath_null+0x1a/0x20
[223879.226148]  [<ffffffffc02cc47a>] intel_display_power_put+0x11a/0x160 [i915]
[223879.226161]  [<ffffffffc031a123>] intel_display_set_init_power+0x33/0x50 [i915]
[223879.226173]  [<ffffffffc031a344>] modeset_update_crtc_power_domains+0x204/0x250 [i915]
[223879.226184]  [<ffffffffc031a39e>] haswell_modeset_global_resources+0xe/0x10 [i915]
[223879.226195]  [<ffffffffc031b1fb>] __intel_set_mode+0x19b/0x420 [i915]
[223879.226206]  [<ffffffffc031e017>] intel_modeset_setup_hw_state+0x357/0x3c0 [i915]
[223879.226212]  [<ffffffffc02bed20>] __i915_drm_thaw+0x130/0x1b0 [i915]
[223879.226219]  [<ffffffffc02bf7a8>] i915_resume+0x28/0x50 [i915]
[223879.226225]  [<ffffffffc02bf7e5>] i915_pm_resume+0x15/0x20 [i915]
[223879.226228]  [<ffffffff823d576e>] pci_pm_resume+0x7e/0xe0
[223879.226229]  [<ffffffff823d56f0>] ? pci_pm_thaw+0x90/0x90
[223879.226232]  [<ffffffff824cfcb8>] dpm_run_callback+0x58/0xd0
[223879.226233]  [<ffffffff820ba423>] ? __wake_up_locked+0x13/0x20
[223879.226235]  [<ffffffff824d08fe>] device_resume+0xee/0x220
[223879.226236]  [<ffffffff824d0a51>] async_resume+0x21/0x50
[223879.226237]  [<ffffffff8209c89b>] async_run_entry_fn+0x3b/0x140
[223879.226240]  [<ffffffff8208e6ff>] process_one_work+0x17f/0x4c0
[223879.226241]  [<ffffffff8208f46b>] worker_thread+0x11b/0x3f0
[223879.226243]  [<ffffffff8208f350>] ? create_and_start_worker+0x80/0x80
[223879.226245]  [<ffffffff82096479>] kthread+0xc9/0xe0
[223879.226246]  [<ffffffff820963b0>] ? flush_kthread_worker+0xb0/0xb0
[223879.226248]  [<ffffffff82793efc>] ret_from_fork+0x7c/0xb0
[223879.226249]  [<ffffffff820963b0>] ? flush_kthread_worker+0xb0/0xb0
[223879.226250] ---[ end trace 128ad953de8a2f86 ]---


and


[224272.119161] ------------[ cut here ]------------
[224272.119185] WARNING: CPU: 0 PID: 1321 at /home/apw/COD/linux/drivers/gpu/drm/i915/intel_pm.c:5997 intel_displ
ay_power_put+0x132/0x160 [i915]()
[224272.119186] Modules linked in: uas usb_storage btrfs xor raid6_pq ufs qnx4 hfsplus hfs minix ntfs msdos jfs x
fs libcrc32c ctr ccm arc4 intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm joydev serio_ra
w iwlmvm mac80211 rfcomm iwlwifi bnep btusb snd_hda_codec_realtek rtsx_pci_ms snd_hda_codec_hdmi snd_hda_codec_ge
neric bluetooth cfg80211 memstick 6lowpan_iphc snd_hda_intel snd_hda_controller snd_hda_codec thinkpad_acpi snd_h
wdep snd_pcm nvram snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq mac_hid intel_smartconnect snd_seq_device 
snd_timer binfmt_misc snd lpc_ich soundcore parport_pc nls_iso8859_1 ppdev lp parport sch_fq dm_crypt rtsx_pci_sd
mmc crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 i915 lrw gf128mul glue_helper ablk_h
elper cryptd psmouse
[224272.119213]  e1000e i2c_algo_bit drm_kms_helper ahci drm libahci ptp rtsx_pci pps_core wmi video [last unloaded: ipmi_msghandler]
[224272.119220] CPU: 0 PID: 1321 Comm: Xorg Tainted: G        W     3.16.0-031600-generic #201408031935
[224272.119221] Hardware name: LENOVO 20AM009DMS/20AM009DMS, BIOS GIET75WW (2.25 ) 06/24/2014
[224272.119222]  000000000000176d ffff8800b6c37aa8 ffffffff82786525 0000000000000007
[224272.119224]  0000000000000000 ffff8800b6c37ae8 ffffffff8207207c ffffffffc03714d7
[224272.119225]  000000000000000b 0000000000000017 ffff88022ab40000 ffff880036621370
[224272.119227] Call Trace:
[224272.119232]  [<ffffffff82786525>] dump_stack+0x46/0x58
[224272.119235]  [<ffffffff8207207c>] warn_slowpath_common+0x8c/0xc0
[224272.119238]  [<ffffffff820720ca>] warn_slowpath_null+0x1a/0x20
[224272.119246]  [<ffffffffc02cc492>] intel_display_power_put+0x132/0x160 [i915]
[224272.119260]  [<ffffffffc031a309>] modeset_update_crtc_power_domains+0x1c9/0x250 [i915]
[224272.119272]  [<ffffffffc031a39e>] haswell_modeset_global_resources+0xe/0x10 [i915]
[224272.119283]  [<ffffffffc031b1fb>] __intel_set_mode+0x19b/0x420 [i915]
[224272.119294]  [<ffffffffc031cda6>] intel_set_mode+0x16/0x30 [i915]
[224272.119305]  [<ffffffffc031d856>] intel_crtc_set_config+0x196/0x300 [i915]
[224272.119316]  [<ffffffffc01da040>] drm_mode_set_config_internal+0x60/0xe0 [drm]
[224272.119325]  [<ffffffffc01de200>] drm_mode_setcrtc+0x280/0x4d0 [drm]
[224272.119328]  [<ffffffff820823af>] ? recalc_sigpending+0x1f/0x60
[224272.119334]  [<ffffffffc01cde76>] drm_ioctl+0x2e6/0x590 [drm]
[224272.119343]  [<ffffffffc01ddf80>] ? drm_mode_setplane+0x470/0x470 [drm]
[224272.119345]  [<ffffffff821f39b5>] do_vfs_ioctl+0x75/0x2c0
[224272.119347]  [<ffffffff820867b9>] ? restore_altstack+0x19/0x30
[224272.119349]  [<ffffffff821fdf85>] ? __fget_light+0x25/0x70
[224272.119351]  [<ffffffff821f3c91>] SyS_ioctl+0x91/0xb0
[224272.119354]  [<ffffffff82793fad>] system_call_fastpath+0x1a/0x1f
[224272.119355] ---[ end trace 128ad953de8a2f8b ]---

Created attachment 105952 [details]
3.16.0 dmesg with drm.debug=0xe

(In reply to comment #4)
> I've since upgraded to 3.16.0 and turned on drm.debug and I think I have the
> same problem but the stack differs.
> 
> I intend to upgrade to the latest 3.17 RC next time I reboot.
> 
> I've concatenated /var/log/dmesg and dmesg. Let me know if you want the
> missing pieces from kern.log.

Thanks. One possibility is that it's the locking issue fixed by:

commit e39b999a6f229386ea6c58cb1c10ce9dc912869b
Author: Ville Syrjälä <ville.syrjala@linux.intel.com>
Date:   Thu Sep 4 14:53:14 2014 +0300

    drm/i915: Fix edp vdd locking
    
It would need backporting to 3.17-rc, so could you also try the
git://anongit.freedesktop.org/drm-intel drm-intel-nightly branch which includes the above fix?

If you can reproduce the problem with that too, could you attach the dmesg log starting from boot? You can increase the log buf size with the log_buf_len kernel parameter. I would need it at least until the first intel_display_power_get/put() warning shows up.

Created attachment 105995 [details]
3.17.0-rc4 dmesg with drm.debug=0xe

3.17.0-rc4 is also affected. Will look at Ville's fix.

(In reply to comment #7)
> Created attachment 105995 [details]
> 3.17.0-rc4 dmesg with drm.debug=0xe
> 
> 3.17.0-rc4 is also affected.

The WARN in this log is separate from the original one. It seems that you have VGA (at least according to your BIOS) but the driver doesn't detect it. Could you try if the diff below fixes it?

> Will look at Ville's fix.

Note that based on the above it's not sure if the original issue is present in 3.17.0-rc4. Did it happen at the first suspend, or only after multiple attempts? Checking if it happens with Ville's fix is still a good next step.

diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c
index 06d3ba3..3682758 100644
--- a/drivers/gpu/drm/i915/intel_display.c
+++ b/drivers/gpu/drm/i915/intel_display.c
@@ -12325,13 +12325,14 @@ static bool intel_crt_present(struct drm_device *dev)
 {
 	struct drm_i915_private *dev_priv = dev->dev_private;
 
-	if (IS_ULT(dev))
+	if (IS_BDW_ULT(dev))
 		return false;
 
 	if (IS_CHERRYVIEW(dev))
 		return false;
 
-	if (IS_VALLEYVIEW(dev) && !dev_priv->vbt.int_crt_support)
+	if ((IS_VALLEYVIEW(dev) || IS_HASWELL(dev)) &&
+	    !dev_priv->vbt.int_crt_support)
 		return false;
 
 	return true;

(In reply to comment #8)
> (In reply to comment #7)
> > 
> > 3.17.0-rc4 is also affected.
> 
> The WARN in this log is separate from the original one.

> It seems that you
> have VGA (at least according to your BIOS) but the driver doesn't detect it.

I do have VGA. Never used it.


> Could you try if the diff below fixes it?

Will do.


> Note that based on the above it's not sure if the original issue is present
> in 3.17.0-rc4. Did it happen at the first suspend, or only after multiple
> attempts?

At first suspend but not at subsequent suspends so far, with 3.17.


I think I have two suspend bugs:

1) intel_display.c: assert_can_disable_lcpll as seen with 3.15 and 3.17

2) intel_pm.c: intel_display_power_put as seen with 3.16 and might be the lock

Maybe #2 also turns up eventually with 3.17. We'll see.

Created attachment 106079 [details]
3.17-rc4 kern.log with patch from comment 8

I applied your patch (but not Ville's) and was greeted with a black screen. The laptop didn't survive a suspend/resume. Lot's of errors in kern.log.

I rebooted to a normal 3.17-rc4 and got hit by both bugs; intel_display_power_put with different stacks. Time to test Ville's patch.

Created attachment 106104 [details]
3.17-rc4 dmesg with Ville's edp vdd locking patch backported

It looks much better after I backported Ville's patch. After a couple of reboots and over ten suspend/resume cycles I've only got one stack dump (which might be my fault).

[   95.314561] Call Trace:
[   95.314564]  [<ffffffff82778f98>] dump_stack+0x45/0x56
[   95.314567]  [<ffffffff8207132d>] warn_slowpath_common+0x7d/0xa0
[   95.314570]  [<ffffffff8207139c>] warn_slowpath_fmt+0x4c/0x50
[   95.314591]  [<ffffffffc0187fe8>] hsw_enable_pc8+0x5b8/0x660 [i915]
[   95.314600]  [<ffffffffc012d1d0>] ? __i915_drm_thaw+0x1d0/0x1d0 [i915]
[   95.314609]  [<ffffffffc012d22b>] i915_pm_suspend_late+0x5b/0x60 [i915]
[   95.314611]  [<ffffffff824d17fc>] dpm_run_callback+0x4c/0x100
[   95.314613]  [<ffffffff824d1fc0>] __device_suspend_late+0xb0/0x1a0
[   95.314615]  [<ffffffff824d20cf>] async_suspend_late+0x1f/0xa0
[   95.314617]  [<ffffffff820930c7>] async_run_entry_fn+0x37/0x130
[   95.314620]  [<ffffffff8208a53a>] process_one_work+0x18a/0x4a0
[   95.314622]  [<ffffffff8208b22b>] worker_thread+0x6b/0x5d0
[   95.314625]  [<ffffffff8208b1c0>] ? pool_mayday_timeout+0x1b0/0x1b0
[   95.314627]  [<ffffffff820905ab>] kthread+0xdb/0x100
[   95.314629]  [<ffffffff820904d0>] ? kthread_create_on_node+0x180/0x180
[   95.314632]  [<ffffffff82780ebc>] ret_from_fork+0x7c/0xb0
[   95.314634]  [<ffffffff820904d0>] ? kthread_create_on_node+0x180/0x180


Imre, please create a new bug for the VGA thingy if you want me to continue testing it.

(In reply to comment #12)
> Created attachment 106104 [details]
> 3.17-rc4 dmesg with Ville's edp vdd locking patch backported
> 
> It looks much better after I backported Ville's patch.

Thanks, we'll consider then backporting Ville's fix.

> After a couple of reboots and over ten suspend/resume cycles
> I've only got one stack dump (which might be my fault).

If you mean the below stacktrace, that's b/c of the VGA thing. It's caused by SPLL being on when we try to enable some power saving mode (PC8), which is an invalid combination. SPLL is only used for VGA, but since we don't even consider enabling VGA for HSW ULT platforms we won't ever touch SPLL. It's still a mistery how it gets enabled though; first I thought it's simply the BIOS during booting, but in your second log it seems to get enabled only before the third suspend, so I have to think about this.

> [   95.314561] Call Trace:
> [   95.314564]  [<ffffffff82778f98>] dump_stack+0x45/0x56
> [   95.314567]  [<ffffffff8207132d>] warn_slowpath_common+0x7d/0xa0
> [   95.314570]  [<ffffffff8207139c>] warn_slowpath_fmt+0x4c/0x50
> [   95.314591]  [<ffffffffc0187fe8>] hsw_enable_pc8+0x5b8/0x660 [i915]
> [   95.314600]  [<ffffffffc012d1d0>] ? __i915_drm_thaw+0x1d0/0x1d0 [i915]
> [   95.314609]  [<ffffffffc012d22b>] i915_pm_suspend_late+0x5b/0x60 [i915]
> [   95.314611]  [<ffffffff824d17fc>] dpm_run_callback+0x4c/0x100
> [   95.314613]  [<ffffffff824d1fc0>] __device_suspend_late+0xb0/0x1a0
> [   95.314615]  [<ffffffff824d20cf>] async_suspend_late+0x1f/0xa0
> [   95.314617]  [<ffffffff820930c7>] async_run_entry_fn+0x37/0x130
> [   95.314620]  [<ffffffff8208a53a>] process_one_work+0x18a/0x4a0
> [   95.314622]  [<ffffffff8208b22b>] worker_thread+0x6b/0x5d0
> [   95.314625]  [<ffffffff8208b1c0>] ? pool_mayday_timeout+0x1b0/0x1b0
> [   95.314627]  [<ffffffff820905ab>] kthread+0xdb/0x100
> [   95.314629]  [<ffffffff820904d0>] ? kthread_create_on_node+0x180/0x180
> [   95.314632]  [<ffffffff82780ebc>] ret_from_fork+0x7c/0xb0
> [   95.314634]  [<ffffffff820904d0>] ? kthread_create_on_node+0x180/0x180
> 
> Imre, please create a new bug for the VGA thingy if you want me to continue
> testing it.

Ok, will do so.

Let's keep this one also open until we decide about a proper fix.

(In reply to comment #13)
> (In reply to comment #12)
> > After a couple of reboots and over ten suspend/resume cycles
> > I've only got one stack dump (which might be my fault).
> 
> If you mean the below stacktrace, that's b/c of the VGA thing.

That's the one. Glad to hear it's not a lock.


> Let's keep this one also open until we decide about a proper fix.

And I will test some more in the meanwhile.

Created attachment 108204 [details]
Linux 3.18-rc1 dmesg with drm.debug=0xe i915.mmio_debug=1

I never experienced the problems after backporting Ville's mutex patch to Linux 3.17 and 3.18-rc1 seems to also include the locking patch but I eventually got this dump, among others, anyway:

------------[ cut here ]------------
WARNING: CPU: 0 PID: 4819 at /home/apw/COD/linux/drivers/gpu/drm/i915/intel_pm.c:6590 intel_display_power_put+0x132/0x160 [i915]()
Modules linked in: ctr ccm arc4 iwlmvm mac80211 iwlwifi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm joydev cfg80211 rtc_efi serio_raw snd_hda_codec_realtek snd_hda_codec_hdmi snd_hda_codec_generic thinkpad_acpi nvram snd_hda_intel lpc_ich snd_hda_controller snd_hda_codec snd_hwdep snd_pcm mac_hid rtsx_pci_ms intel_smartconnect snd_seq_midi memstick snd_seq_midi_event btusb rfcomm shpchp bnep bluetooth snd_rawmidi snd_seq snd_seq_device snd_timer snd soundcore binfmt_misc parport_pc ppdev nls_iso8859_1 lp parport sch_fq dm_crypt rtsx_pci_sdmmc crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper i915 cryptd psmouse e1000e ahci i2c_algo_bit libahci ptp drm_kms_helper rtsx_pci pps_core drm wmi video [last unloaded: ipmi_msghandler]
CPU: 0 PID: 4819 Comm: kworker/0:3 Tainted: G        W      3.18.0-031800rc1-generic #201410192135
Hardware name: LENOVO 20AM009DMS/20AM009DMS, BIOS GIET76WW (2.26 ) 08/27/2014
Workqueue: events edp_panel_vdd_work [i915]
 00000000000019be ffff880231aa7d08 ffffffff827a1613 ffffffff82c54168
 0000000000000000 ffff880231aa7d48 ffffffff82074cfc ffff88022dd70000
 000000000000000b 0000000000000017 ffff88022dd70000 0000000000000000
Call Trace:
 [<ffffffff827a1613>] dump_stack+0x46/0x58
 [<ffffffff82074cfc>] warn_slowpath_common+0x8c/0xc0
 [<ffffffff82074d4a>] warn_slowpath_null+0x1a/0x20
 [<ffffffffc016ad52>] intel_display_power_put+0x132/0x160 [i915]
 [<ffffffffc01dac86>] pps_unlock+0x46/0x50 [i915]
 [<ffffffffc01dd012>] edp_panel_vdd_work+0x42/0x50 [i915]
 [<ffffffff8208d6be>] process_one_work+0x14e/0x460
 [<ffffffff8208e03b>] worker_thread+0x11b/0x3f0
 [<ffffffff8208df20>] ? create_worker+0x1e0/0x1e0
 [<ffffffff82093bb9>] kthread+0xc9/0xe0
 [<ffffffff82093af0>] ? flush_kthread_worker+0x90/0x90
 [<ffffffff827aeebc>] ret_from_fork+0x7c/0xb0
 [<ffffffff82093af0>] ? flush_kthread_worker+0x90/0x90
---[ end trace c7d449c4daccb3b6 ]---
------------[ cut here ]------------

That last backtrace might be fixed now, can you try a drm-intel-nightly kernel from git://anongit.freedesktop.org/drm-intel?

Jesse, I compiled drm-intel from 19th December (commit 4fa23142a15526f4a4b5df61f26eacdd558a849a) and have been running it since without seeing the last backtrace (intel_display_power_put) again.

Thanks for the follow-up, sorry for the delay, closing.