Bug 91845 - [HSW]i915 does 2s long DP-link-reset (backlight off) during modeset instead of re-using SimpleFB, stacktrace with i915.fastboot=1
Summary: [HSW]i915 does 2s long DP-link-reset (backlight off) during modeset instead o...
Status: CLOSED FIXED
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: unspecified
Hardware: x86-64 (AMD64) Linux (All)
: high normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard: ReadyForDev
Keywords:
Depends on:
Blocks:
 
Reported: 2015-09-02 01:57 UTC by o.freyermuth
Modified: 2018-10-23 09:26 UTC (History)
3 users (show)

See Also:
i915 platform: HSW
i915 features: display/DP


Attachments
dmesg from boot with: "pcie_aspm=force i915.fastboot=1 drm.debug=0x06" (146.97 KB, text/plain)
2015-09-02 01:57 UTC, o.freyermuth
no flags Details
dmesg from boot with "pcie_aspm=force drm.debug=0x06" (132.53 KB, text/plain)
2015-09-02 01:58 UTC, o.freyermuth
no flags Details
dmesg from boot with: "pcie_aspm=force drm.debug=0x06" on Kernel 4.14.12 (106.16 KB, text/plain)
2018-01-07 02:12 UTC, o.freyermuth
no flags Details
dmesg from boot with: "pcie_aspm=force i915.enable_fbc=1 pcie_port_pm=off drm.debug=0x1e log_buf_len=4M" (195.53 KB, text/plain)
2018-09-11 20:55 UTC, o.freyermuth
no flags Details
dmesg from boot of drm-tip with: "pcie_aspm=force i915.enable_fbc=1 pcie_port_pm=off drm.debug=0x1e log_buf_len=4M" (200.93 KB, text/plain)
2018-09-11 21:35 UTC, o.freyermuth
no flags Details

Description o.freyermuth 2015-09-02 01:57:25 UTC
Created attachment 118043 [details]
dmesg from boot with: "pcie_aspm=force i915.fastboot=1 drm.debug=0x06"

Bug description:
System is EFI-booted (via refind), efifb with native resolution is available. 
During modeset, display backlight is turned off for ~2 s, drm.debug=0x06 reveals DP and panel are fully reset. 

Forcing i915.fastboot=1 produces the following messages (from attached dmesg):
...
[    0.528989] [drm:intel_fbdev_init_bios] using BIOS fb for initial console
...
[    0.602811] [drm:intelfb_create] re-using BIOS fb
...
i.e. all fine, but then: 
...
[    0.611868] [drm:intel_edp_backlight_off]
...
...
[    1.813729] [drm:intel_panel_actually_set_backlight] set backlight PWM = 0
[    1.825971] [drm:edp_panel_off] Turn eDP port A panel power off
[    1.825977] [drm:wait_panel_off] Wait for panel power off time
[    2.868867] [drm:intel_psr_enable] PSR not supported by this panel
[    2.868868] [drm:intel_edp_drrs_enable] Panel doesn't support DRRS
[    2.868876] ------------[ cut here ]------------
[    2.868882] WARNING: CPU: 7 PID: 36 at drivers/gpu/drm/i915/intel_uncore.c:620 hsw_unclaimed_reg_debug+0x65/0x7e()
[    2.868885] [drm:intel_uncore_check_errors] *ERROR* Unclaimed register before interrupt
[    2.868886] Unclaimed register detected after writing to register 0x68070
[    2.868887] Modules linked in:
[    2.868890] CPU: 7 PID: 36 Comm: kworker/7:0 Not tainted 4.2.0-gentoo #4
[    2.868891] Hardware name: Clevo W230SD                 /powered by premamod.com, BIOS 1.03.04PM v1 07/09/2015
[    2.868895] Workqueue: events output_poll_execute
[    2.868897]  0000000000000009 ffff88041db639f8 ffffffff8191b0a0 0000000000000001
[    2.868899]  ffff88041db63a48 ffff88041db63a38 ffffffff81052be9 ffff88041db63a38
[    2.868901]  ffffffff8156bd36 ffff88041ae80000 0000000000068070 ffff88041ae80080
[    2.868902] Call Trace:
[    2.868906]  [<ffffffff8191b0a0>] dump_stack+0x45/0x57
[    2.868910]  [<ffffffff81052be9>] warn_slowpath_common+0x9c/0xb6
[    2.868912]  [<ffffffff8156bd36>] ? hsw_unclaimed_reg_debug+0x65/0x7e
[    2.868914]  [<ffffffff81052c44>] warn_slowpath_fmt+0x41/0x43
[    2.868917]  [<ffffffff81082972>] ? arch_local_irq_save+0x15/0x1b
[    2.868919]  [<ffffffff8156bd36>] hsw_unclaimed_reg_debug+0x65/0x7e
[    2.868921]  [<ffffffff8156edfa>] hsw_write32+0xa8/0xca
[    2.868924]  [<ffffffff8157b99e>] intel_update_pipe_size+0xef/0x145
[    2.868926]  [<ffffffff8157ba51>] intel_commit_primary_plane+0x5d/0x83
[    2.868929]  [<ffffffff8159811a>] intel_plane_atomic_update+0x14/0x16
[    2.868932]  [<ffffffff8150bde2>] drm_atomic_helper_commit_planes_on_crtc+0x112/0x166
[    2.868934]  [<ffffffff81582c63>] __intel_set_mode+0x8b5/0x8e1
[    2.868937]  [<ffffffff81588954>] intel_crtc_set_config+0x3fb/0x4c0
[    2.868940]  [<ffffffff8151b536>] drm_mode_set_config_internal+0x57/0xe3
[    2.868942]  [<ffffffff8150c847>] restore_fbdev_mode+0xb5/0xcf
[    2.868944]  [<ffffffff8150e155>] drm_fb_helper_restore_fbdev_mode_unlocked+0x22/0x59
[    2.868946]  [<ffffffff8150e1bd>] drm_fb_helper_set_par+0x31/0x35
[    2.868948]  [<ffffffff8150e12c>] drm_fb_helper_hotplug_event+0xa6/0xad
[    2.868950]  [<ffffffff81595623>] intel_fbdev_output_poll_changed+0x19/0x1b
[    2.868952]  [<ffffffff815050d6>] drm_kms_helper_hotplug_event+0x23/0x27
[    2.868954]  [<ffffffff8150522d>] output_poll_execute+0x12d/0x14e
[    2.868956]  [<ffffffff810950d6>] ? lock_timer_base.isra.33+0x42/0x68
[    2.868958]  [<ffffffff81095a58>] ? mod_timer+0x7c/0x83
[    2.868961]  [<ffffffff81065375>] process_one_work+0x152/0x272
[    2.868963]  [<ffffffff8106591c>] worker_thread+0x1eb/0x29a
[    2.868966]  [<ffffffff81065731>] ? rescuer_thread+0x272/0x272
[    2.868968]  [<ffffffff810697fe>] kthread+0xa0/0xa8
[    2.868970]  [<ffffffff8106975e>] ? kthread_parkme+0x1f/0x1f
[    2.868973]  [<ffffffff81921d5f>] ret_from_fork+0x3f/0x70
[    2.868975]  [<ffffffff8106975e>] ? kthread_parkme+0x1f/0x1f
[    2.868976] ---[ end trace abe6cc7ab4fd79a7 ]---
[    2.868989] [drm:intel_uncore_check_errors] *ERROR* Unclaimed register before interrupt

Stacktrace not observed without i915.fastboot=1, but the 2 seconds with backlight off during boot are always there (supposedly prolonging the overall boot time significantly). 

System environment:
-- Gentoo Linux 4.2.0 x86_64
-- Machine: Clevo W230SD (Schenker XMG A305)
-- Display connector: Internal Panel, DP connected

Additional info:
-- Machine has nVidia Optimus (should not be relevant here)
Comment 1 o.freyermuth 2015-09-02 01:58:08 UTC
Created attachment 118044 [details]
dmesg from boot with "pcie_aspm=force drm.debug=0x06"
Comment 2 Dhinakaran Pandiyan 2016-06-23 22:38:13 UTC
Thanks for reporting the bug. Can you please re-test with the latest drm-intel-nightly and post the logs?
Comment 3 Dhinakaran Pandiyan 2016-06-23 22:52:57 UTC
Never mind, booting with i915.fastboot=1 caused flickers with drm-intel-nightly

commit 9201a72678f7320974c28b9f704b802b2c1a43c1
Author: Jani Nikula <jani.nikula@intel.com>
Date:   Wed Jun 22 00:27:00 2016 +0300

    drm-intel-nightly: 2016y-06m-21d-21h-26m-35s UTC integration manifest

dmesg shows
 link training failures 
 several dp_aux_ch timeouts
Comment 4 Jari Tahvanainen 2017-03-17 13:45:42 UTC
o.freyermuth@googlemail.com, Please check if this is still problem with the latest drm-tip.
Comment 5 Elizabeth 2017-06-28 20:19:52 UTC
(In reply to Jari Tahvanainen from comment #4)
> o.freyermuth@googlemail.com, Please check if this is still problem with the
> latest drm-tip.

Hello,
I'm closing this bug since the reported has not updated any new information here. If there is any new relevant information on this case, please share it and mark as REOPEN. Thanks.
Comment 6 o.freyermuth 2018-01-07 02:09:29 UTC
Sorry for the by far too long delay. 

I still observe the issue after updating to 4.14.12. 

I'll attach a full dmesg from booting with "pcie_aspm=force drm.debug=0x06", basically I still see the same:

[    0.608073] [drm:intelfb_create] re-using BIOS fb
but then...
[    0.608321] [drm:intel_edp_backlight_off]
[...]
[    1.823031] [drm:intel_panel_actually_set_backlight] set backlight PWM = 0
[    1.823037] [drm:lpt_disable_backlight] cpu backlight was enabled, disabling
[    1.823051] [drm:intel_disable_pipe] disabling pipe A
[    1.839572] [drm:intel_edp_panel_off] Turn eDP port A panel power off
[    1.839578] [drm:intel_edp_panel_off] Wait for panel power off time
[    1.839589] [drm:wait_panel_status] mask b0000000 value 00000000 status 80000008 control 00000000
[    1.840248] [drm:ilk_hpd_irq_handler] hotplug event received, stat 0x08000000, dig 0x00000011, pins 0x00000010
[    1.840253] [drm:intel_hpd_irq_handler] digital hpd port A - short
[    1.840271] [drm:intel_dp_hpd_pulse] got hpd irq on port A - short
[    1.890256] [drm:wait_panel_status] Wait complete
[    1.890271] [drm:intel_disable_shared_dpll] disable LCPLL 1350 (active 1, on? 1) for crtc 36
[    1.890273] [drm:intel_disable_shared_dpll] disabling LCPLL 1350
[    1.890283] [drm:intel_atomic_commit_tail] [ENCODER:57:DDI A]
[    1.890291] [drm:edp_panel_vdd_on] Turning eDP port A VDD on
[    1.890294] [drm:intel_atomic_commit_tail] [ENCODER:67:DDI C]
[    1.890298] [drm:wait_panel_power_cycle] Wait for panel power cycle
and only then:
[    3.138783] [drm:intel_dp_start_link_train] Channel EQ done. DP Training successful
[    3.138790] [drm:intel_dp_start_link_train] [CONNECTOR:58:eDP-1] Link Training Passed at Link Rate = 270000, Lane count = 2
[    3.138874] [drm:intel_enable_pipe] enabling pipe A
[    3.139052] [drm:intel_edp_backlight_on] 
[    3.139059] [drm:intel_panel_enable_backlight] pipe A

So for some reason, it seems the panel is fully powercycled on boot, instead of re-using the existing FB, leaving the screen completely dark for about 2 seconds.
Comment 7 o.freyermuth 2018-01-07 02:12:08 UTC
Created attachment 136590 [details]
dmesg from boot with: "pcie_aspm=force drm.debug=0x06" on Kernel 4.14.12
Comment 8 Jani Saarinen 2018-03-29 07:10:00 UTC
First of all. Sorry about spam.
This is mass update for our bugs. 

Sorry if you feel this annoying but with this trying to understand if bug still valid or not.
If bug investigation still in progress, please ignore this and I apologize!

If you think this is not anymore valid, please comment to the bug that can be closed.
If you haven't tested with our latest pre-upstream tree(drm-tip), can you do that also to see if issue is valid there still and if you cannot see issue there, please comment to the bug.
Comment 9 Jani Saarinen 2018-04-22 15:33:23 UTC
Closing, please re-open if still occurs.
Comment 10 o.freyermuth 2018-04-22 17:42:44 UTC
Still happens as of kernel 4.16.3. 

Let me know if more info is needed - my last boot logs were from 4.14.12 and I got no developer response at all, but the bug was closed seemingly without investigation.
Comment 11 Jani Saarinen 2018-04-23 06:40:16 UTC
Can you try with latest drm-tip still?
https://cgit.freedesktop.org/drm-tip
Comment 12 o.freyermuth 2018-04-23 19:11:45 UTC
Tried with latest drm-tip as of fb7048acaac8ece5ebc53f9b748b76cdcef60fa3 using the same kernel configuration I used with 4.16.3 (after running make oldconfig). 
I end up with a blank, but lighted screen *immediately* after the bootloader. 

Neither sysrq nor any other keypresses apart from turning the machine hard off are working. 
No stacktraces found in pstore. 

Other ideas?
Comment 13 Jani Saarinen 2018-04-24 06:32:49 UTC
Ville, any suggestions?
Comment 14 Lakshmi 2018-09-11 08:20:53 UTC
Sorry for the delay...

Reporter, do you still have the issue?
Please try to reproduce the issue using drm-tip (https://cgit.freedesktop.org/drm-tip) and kernel parameters drm.debug=0x1e log_buf_len=4M, and if the problem persists attach the full dmesg from boot.

This will help us to set the right priority and speed up the investigation.
Comment 15 o.freyermuth 2018-09-11 20:55:43 UTC
Created attachment 141529 [details]
dmesg from boot with: "pcie_aspm=force i915.enable_fbc=1 pcie_port_pm=off drm.debug=0x1e log_buf_len=4M"

I can still reproduce with 4.18.3, albeit the delay has become slightly lower, but the panel is still reset and powercycled as the logs indicate. 
I've attached full dmesg from "drm.debug=0x1e log_buf_len=4M". 

Will reproduce with drm-tip as soon as I get to that in the next days, but maybe the log from a recent kernel already helps to categorize the issue.
Comment 16 o.freyermuth 2018-09-11 21:35:27 UTC
Created attachment 141530 [details]
dmesg from boot of drm-tip with: "pcie_aspm=force i915.enable_fbc=1 pcie_port_pm=off drm.debug=0x1e log_buf_len=4M"

That was faster than expected. Here you go, that's a log from drm-tip as of 25e1692db98d624ae01610ae4fee1e9247e19fe9. Issue prevails.
Comment 17 Ville Syrjala 2018-10-19 14:38:06 UTC
The modeset is slow due to long panel power delays declared in the VBT.

[    0.568400] [drm:intel_pps_dump_state] cur t1_t3 0 t8 0 t9 0 t10 500 t11_t12 6000
[    0.568402] [drm:intel_pps_dump_state] vbt t1_t3 3000 t8 1000 t9 12000 t10 500 t11_t12 6000
[    0.568404] [drm:intel_dp_init_panel_power_sequencer] panel power up delay 300, power down delay 50, power cycle delay 600
[    0.568406] [drm:intel_dp_init_panel_power_sequencer] backlight on delay 100, off delay 1200

The backlight off delay in particular is 1.2 seconds. Not much we can do about that.
Comment 18 o.freyermuth 2018-10-19 14:52:50 UTC
I understand, yes, that matches observation. 
Still: Why is the panel toggled at all? 
Shouldn't it be possible to just take over the efifb? 
It seems a full reinitialization is taking place, and the panel toggling is just part of that.
Comment 19 Ville Syrjala 2018-10-22 14:04:32 UTC
(In reply to o.freyermuth from comment #18)
> I understand, yes, that matches observation. 
> Still: Why is the panel toggled at all? 
> Shouldn't it be possible to just take over the efifb? 
> It seems a full reinitialization is taking place, and the panel toggling is
> just part of that.

I suppose it's the lack of fastboot. That thing is still not entirely implemented. You can try it with the modparam but not really guaranteed to do the right thing.
Comment 20 o.freyermuth 2018-10-22 19:18:49 UTC
You are correct!
I tried i915.fastboot=1 on a 4.18 kernel, and apart from a short corruption for less than a second (only a small region on the top left was filled with kernel messages, albeit resolution was fine), the panel power cycling was completely gone! No "black pause" anymore! 
Even the corruption does not always show up. 

So I think this can be closed as solved, unless you want to investigate fastboot with verbose logging.
Comment 21 Ville Syrjala 2018-10-23 09:19:45 UTC
(In reply to o.freyermuth from comment #20)
> You are correct!
> I tried i915.fastboot=1 on a 4.18 kernel, and apart from a short corruption
> for less than a second (only a small region on the top left was filled with
> kernel messages, albeit resolution was fine), the panel power cycling was
> completely gone! No "black pause" anymore! 
> Even the corruption does not always show up. 
> 
> So I think this can be closed as solved, unless you want to investigate
> fastboot with verbose logging.

OK. Let's mark this as fixed.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.