Created attachment 51432 [details]
BootDmesg.txt

Created attachment 51433 [details]
XorgConf.txt

Created attachment 51434 [details]
XorgLog.txt

User reported that by disabling HDMI1 as described, it returns boot speed performance to what it was under natty.

Presumably HDMI1 could be quirked off in the kernel for this particular laptop, but is there a better solution?

Right, let's have a look at drm.debug=0xe for starters. Though I don't think that will tell us anything more than the probe is slow. We can try the initcall_debug trick here (again requires a builtin i915.ko I think) to narrow down the offending function. The most likely suspect is that it is the EDID discovery that is slow.

Created attachment 51505 [details]
dmesg with debug output

Well, that pinpoints it entirely on the EDID probe for the HDMI port. So it would appear to be that we valiantly try to read the EDID through a sea of noise.

Just on the off-chance this helps and points us in the right direction, can you try:

diff --git a/drivers/gpu/drm/i915/intel_i2c.c b/drivers/gpu/drm/i915/intel_i2c.c
index d98cee6..1b14504 100644
--- a/drivers/gpu/drm/i915/intel_i2c.c
+++ b/drivers/gpu/drm/i915/intel_i2c.c
@@ -401,7 +401,7 @@ int intel_setup_gmbus(struct drm_device *dev)
                bus->reg0 = i | GMBUS_RATE_100KHZ;
 
                /* XXX force bit banging until GMBUS is fully debugged */
-               bus->force_bit = intel_gpio_create(dev_priv, i);
+               //bus->force_bit = intel_gpio_create(dev_priv, i);
        }
 
        intel_i2c_reset(dev_priv->dev);

*** Bug 41061 has been marked as a duplicate of this bug. ***

I'm the original reporter of the dupe. The patch actually worsen the time by a bit. From only my LVDS1 activated, I successively un-ignored the other outputs via xorg.conf and checked the time `xrandr` needed to finish (mean over 10 runs):

* Ubuntu kernel (3.0.0-11.18) and 3.1-rc7 w/o patch (using the Ubuntu config):

LVDS1        5 ms (connected)
+ VGA1       6 ms (disconnected)
+ DP3      120 ms (not present)
+ DP2      240 ms (not present)     
+ DP1      360 ms (disconnected)
+ HDMI3    380 ms (not present)     
+ HDMI2    400 ms (not present)     
+ HDMI1   2000 ms (not present)

* 3.1-rc7 patched (using the Ubuntu config):

LVDS1        5 ms (connected)
+ VGA1       6 ms (disconnected)
+ DP3      120 ms (not present)
+ DP2      240 ms (not present)     
+ DP1      360 ms (disconnected)
+ HDMI3    380 ms (not present)     
+ HDMI2    590 ms (not present)     
+ HDMI1   2200 ms (not present)

Besides: are 120 ms for the (disconnected and non-existent) DisplayPort ports okay?

Well that rules out the possibility that the hardware GMBUS handles the failure more graceful.

To determine if VGA is connected we first check a hotplug status bit in a register. So determining if it is disconnected is quick and easy.

For everything else, we more or less, probe for an EDID and check that EDID corresponds with the limitations of the link. (There are many machines out there that share a single DDC bus between multiple devices, and so the EDID you receive might be for a different encoder.)

Next step is to dive into the specs and see if there is a method for quickly determining unconnected status that we've overlooked all these years...

Besides which the timeout for the HDMI is inexplicably long.

For anyone else interested (ie Soren), I've built an Ubuntu test kernel with the patch from comment #7 applied.  It's available at the following location:

http://people.canonical.com/~ogasawara/fdo41059/

Wow, how awesome is that? :) I'll take it for spin right away.

It certainly made a difference.

If I don't disable any of the outputs, xrandr takes nearly 4 seconds without the patch, and around 0.6 with the patch.

If I disable HDMI1, xrandr runtime gets down to 0.125 seconds or thereabouts.

Created attachment 51643 [details] [review]
Patch to ignore non-existent i2c buses

Could you please try with this patch?

It should allow kernel to ignore non-existent i2c communication lines.

On my machine, the xrandr probing with this patch went from 4s to 0.366s.

To enable it, please also add the following line into /etc/modprobe.conf (or /etc/modprobe.d/i2c_algo_bit.conf file (creating it when necessary):

options i2c_algo_bit bit_test=1

Also, if it works (or if it does not works) for you, please paste the result of 'dmesg' with the patch applied.

Created attachment 51687 [details] [review]
Patch to detect stuck bits directly in i915 driver

This patch avoids going through i2c_algo_bit to do the bus testing and performs the testing directly in the i915 driver.

It tests only for the bits which are stuck as high, which seems to be the case if this issue.

Please test with both patches (this and the previous one), and report if they fix the issue for you. At least on my machine, I haven't experienced delays in xrandr and video output detection with any of those patches anymore.

(In reply to comment #15)
> Please test with both patches (this and the previous one)

Err.. clarifying, I meant "please test each of those patches". They do similar thing, but in two different ways, let's find out which one works better for this specific case.

Hi Soren,

I've built Ubuntu test kernels for each of the patches mentioned in comment 14 and comment 15.  They are available at the following locations.  Please test and let Eugeni know your results.  Thanks.

http://people.canonical.com/~ogasawara/fdo41059/comment14/

http://people.canonical.com/~ogasawara/fdo41059/comment15/

Awesome! Thanks, Leann!

I'll try them out right away.

These are the timings for running xrandr with hdmi1 enabled and disabled for the patches from comment 14 and 15:

comment14/with-hdmi1-disabled:real	0m0.115s
comment14/with-hdmi1-enabled:real	0m0.646s
comment15/with-hdmi1-disabled:real	0m0.040s
comment15/with-hdmi1-enabled:real	0m0.041s

So the one from comment15 is clearly the winner. Switching feels instant.

(In reply to comment #19)
> These are the timings for running xrandr with hdmi1 enabled and disabled for
> the patches from comment 14 and 15:
> 
> comment14/with-hdmi1-disabled:real    0m0.115s
> comment14/with-hdmi1-enabled:real    0m0.646s
> comment15/with-hdmi1-disabled:real    0m0.040s
> comment15/with-hdmi1-enabled:real    0m0.041s
> 
> So the one from comment15 is clearly the winner. Switching feels instant.

Great to know that it works! :)

Could you also post the dmesg output with both of those patches please?

(In reply to comment #20)
> (In reply to comment #19)
> > So the one from comment15 is clearly the winner. Switching feels instant.
> Great to know that it works! :)
> Could you also post the dmesg output with both of those patches please?

Of course, sorry.

Created attachment 51766 [details]
debug dmesg (patch from comment 14)

Created attachment 51767 [details]
debug dmesg (patch from comment 15)

Sorry for the late answer. I also tested with Leann's kernels (thanks for providing them!) and got different (but not too bad) results:

Ubuntu kernel 3.0.0-12.19
* HDMI1 enabled:  1400 ms
* HDMI1 ignored:   800 ms

Ubuntu kernel 3.0.0-12.20~fdo41059cmt14 + bit_test=1
* HDMI1 enabled:   150 ms
* HDMI1 ignored:   150 ms

Ubuntu kernel 3.0.0-12.20~fdo41059cmt15
* HDMI1 enabled:   150 ms
* HDMI1 ignored:   150 ms

So both cases are equally better than the original one (I have no idea why those numbers changed so much from Ubuntu's kernel 3.0.0-12.18 to 3.0.0-12.19).

Created attachment 51835 [details]
dmesg_cmt14_enabled

Created attachment 51836 [details]
dmesg_cmt15_enabled

Re-tested with DisplayPort ports DP1-3 ignored (so only LVDS1, VGA1 and HDMI1-3 enabled) and got decent results for both patches:

Ubuntu kernel 3.0.0-12.20~fdo41059cmt14 + bit_test=1, DP1-3 ignored
* HDMI1 enabled:   6 ms
* HDMI1 ignored:   4 ms

Ubuntu kernel 3.0.0-12.20~fdo41059cmt15, DP1-3 ignored
* HDMI1 enabled:   6 ms
* HDMI1 ignored:   6 ms

I wanted to test this with a second system (Z68 based with an Intel HD Graphics 3000), but xrandr shows HDMI1 being in use (monitor is connected via DVI), so I got no idea what to do there.

The patch from comment 15 is causing trouble on my second system (monitor connected via DVI, shown as HDMI1 by xrandr): the monitor loses the signal early in the boot process.

Times with the patch in comment 14 didn't change (170 ms for VGA1, HDMI1-3, and ignored DP1-3).

Attaching both dmesg logs.

Created attachment 51842 [details]
dmesg_sys2_cmt15_fail

Created attachment 51843 [details]
dmesg_sys2_cmt14_good

Created attachment 52057 [details] [review]
Give up on DDC detection when i2c tells us

Ok, so we got mixed results with the previous patches, and after some investigation I finally found out why they don't work.

What happens with some of the hot-pluggable connectors is that while they are not ready, the bits stay "stuck" (and the patches were detecting that correctly). As soon as they are, they are no longer stuck - but it is too late now, because previous patches already marked them as ignored.

So by checking all the events I am getting, I can consistently detect whether the connection is not there earlier - it is being indicated by the -ENXIO error code being returned by the i2c_transfer call. In this case, I modified drm_do_probe_ddc_edid to return earlier and avoid having try repeatable to talk over those pins.

With this patch, each time a display detection is being performed (for example, by running xrandr), the kernel should list the pins that are being ignored into the dmesg output, so please attach it with the testing results.

Just for safety: this patch shouldn't be combined with the other two, right?

No, only this patch. The other patches are not necessary anymore.

Created attachment 52062 [details] [review]
Another way to do the check if bus is alive

Besides the previous patch, if you could test this one as well, it would be great!

It does a similar thing to the previous patch, but only affects i915 driver, while the previous one also modifies the edid detection for other drm drivers (nouveau, radeon, ...).

This patch adds a check for i2c connectivity prior to getting the edid data. It could be slightly faster than the previous one in case the connection is not there (e.g., it could greatly reduce the delay with xrandr with phantom outputs), and potentially a bit slower when the bus is present (e.g., it could increment by some ms the xrandr time for valid outputs).

As with the previous patch, this one should be tested on its own.

Sorry for all those patches, I am trying to figure out a way to fix it properly, once and for all :).

Again both patches are equally fast (but slower than the previous ones):

Ubuntu kernel 3.0.0-12.19:
- HDMI1 enabled: 840 ms (690 ms with DP1-3 ignored)
- HDMI1 ignored: 200 ms ( 50 ms with DP1-3 ignored)

With patch from comment 31 (abort early/drm):
- HDMI1 enabled: 290 ms (140 ms with DP1-3 ignored)
- HDMI1 ignored: 160 ms ( 15 ms with DP1-3 ignored)

With patch from comment 34 (valid bus/i915):
- HDMI1 enabled: 290 ms (140 ms with DP1-3 ignored)
- HDMI1 ignored: 160 ms ( 15 ms with DP1-3 ignored)

Will test the second system with active HDMI1 (really DVI) tomorrow.

Created attachment 52065 [details]
dmesg w/ patch comment 31

Created attachment 52066 [details]
dmesg from xrandr w/ patch comment 31

Created attachment 52067 [details]
dmesg w/ patch comment 34

Created attachment 52068 [details]
dmesg from xrandr w/ patch comment 34

Great, thanks a lot for the testing and the feedback!

The patches are a bit slower than the previous one because they attempt to improve performance while still detecting all the possible output consistently all the time. For some outputs (such as hdmi), it turned out that it is impossible to say whether they are present or not without at least one ddc query - so it should take some ms. But with those patches, we can detect if an output is not really there, so we do not keep retrying until the final timeout and give up faster.

Here are the results for the second system:

Ubuntu kernel 3.0.0-12.19:
- All:          315 ms (175 ms with DP1-3 ignored)
- Only HDMI1:   130 ms

With patch from comment 31 (abort early/drm):
- All:          280 ms (140 ms with DP1-3 ignored)
- Only HDMI1:   130 ms

With patch from comment 34 (valid bus/i915):
- All:          280 ms (140 ms with DP1-3 ignored)
- Only HDMI1:   130 ms

I obviously couldn't test with HDMI1 ignored, so that's all outputs vs. only HDMI1. Both patches were equally fast again.

Created attachment 52074 [details]
PC dmesg w/ patch comment 31

Created attachment 52075 [details]
PC dmesg from xrandr w/ patch comment 31

Created attachment 52076 [details]
PC dmesg w/ patch comment 34

Created attachment 52077 [details]
PC dmesg from xrandr w/ patch comment 34

Hi Soren,

In case you are interested in testing the patches from comments #31 and #34, I've built an Ubuntu test kernel for each patch and placed them at the following locations.  Thanks.

http://people.canonical.com/~ogasawara/fdo41059/comment31/

http://people.canonical.com/~ogasawara/fdo41059/comment34/

(In reply to comment #46)
> In case you are interested in testing the patches from comments #31 and #34,
> I've built an Ubuntu test kernel for each patch and placed them at the
> following locations.  Thanks.
> 
> http://people.canonical.com/~ogasawara/fdo41059/comment31/
> 
> http://people.canonical.com/~ogasawara/fdo41059/comment34/

Lovely, thanks!


comment31

With HDMI1 disabled, xrandr takes 0.086s on average to complete.
With HDMI1 enabled, xrandr takes 0.185s on average to complete.

comment34

With HDMI1 disabled, xrandr takes 0.085s on average to complete.
With HDMI1 enabled, xrandr takes 0.184s on average to complete.

Final patches landed into intel-gfx list, thank you all for testing and feedback!

Hopefully they will reach kernel soon :).

Hi,  after getting hinted to this from the kind folks in #debian-x, I'd like to report that this does also affect radeon systems as well.  I have a radeon HD5770, and somewhere around 3.0ish I started seeing this behavior too.

I'd like to confirm that the non-intel-specific patch also helps on my system, though the problem is still clearly there.  Instead of a dozen (or more) 2-second stutter/hangs as the system comes up, it's a dozen half second hangs, or feels something roughly like that.  But to add some objective measures, here's some "time xrandr" outputs from the different combinations of patch/xorg config:

without patch, no xorg.conf "Ignore":, 3.210
with patch, no xorg.conf "Ignore": 1.060
with patch, with xorg.conf "Ignore": 0.120
without patch, with xorg.conf "Ignore": 0.117

I'd say the last two are statistically equivalent, but there is still an obvious problem even with the patch, though it seems to be much less of one.

This is running master as of this morning, using the radeon HD5770 card connected over HDMI.  The following is the "Ignore" config referenced above:

Section "Monitor"
        Identifier "DisplayPort-0"
        Option "Ignore" "True"
EndSection
Section "Monitor"
        Identifier "DVI-0"
        Option "Ignore" "True"
EndSection
Section "Monitor"
        Identifier "DVI-1"
        Option "Ignore" "True"
EndSection

In airlied/drm-next:

commit 9292f37e1f5c79400254dca46f83313488093825
Author: Eugeni Dodonov <eugeni.dodonov@intel.com>
Date:   Thu Jan 5 09:34:28 2012 -0200

    drm: give up on edid retries when i2c bus is not responding
    
    This allows to avoid talking to a non-responding bus repeatedly until we
    finally timeout after 15 attempts. We can do this by catching the -ENXIO
    error, provided by i2c_algo_bit:bit_doAddress call.
    
    Within the bit_doAddress we already try 3 times to get the edid data, so
    if the routine tells us that bus is not responding, it is mostly pointless
    to keep re-trying those attempts over and over again until we reach final
    number of retries.
    
    This change should fix https://bugs.freedesktop.org/show_bug.cgi?id=41059
    and improve overall edid detection timing by 10-30% in most cases, and by
    a much larger margin in case of phantom outputs (up to 30x in one worst
    case).
    
    Timing results for i915-powered machines for 'time xrandr' command:
    Machine 1: from 0.840s to 0.290s
    Machine 2: from 0.315s to 0.280s
    Machine 3: from +/- 4s to 0.184s
    
    Timing results for HD5770 with 'time xrandr' command:
    Machine 4: from 3.210s to 1.060s
    
    Reviewed-by: Chris Wilson <chris@hchris-wilson.co.uk>
    Reviewed-by: Keith Packard <keithp@keithp.com>
    Tested-by: Sean Finney <seanius@seanius.net>
    Tested-by: Soren Hansen <soren@linux2go.dk>
    Tested-by: Hernando Torque <sirius@sonnenkinder.org>
    Tested-by: Mike Lothian <mike@fireburn.co.uk>
    Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=41059
    Signed-off-by: Eugeni Dodonov <eugeni.dodonov@intel.com>
    Signed-off-by: Dave Airlie <airlied@redhat.com>

Please test and report if this does not resolve the problem for you. In some instances we may need to teach the application to use RRGetScreenResourcesCurrent rather than RRGetScreenResources.

Ubuntu build of drm-next kernel is here for anyone wishing to test:

http://kernel.ubuntu.com/~kernel-ppa/mainline/drm-next/

I checked the patch from comment 15 against 3.1.1. While xrandr is faster switching my screen it still takes a long time (3.8 seconds) to read out the current information.
What is worse during switching or asking the information X is blocking! meaning not even the mouse is moving. This also happens when other applications ask for display information (e.g. wine seems to do that a lot).

I reported a separate issue for this bug 47059

oh, forgot to mention, I have HDMI1 and DP2 and use them both in a dual screen setup

is this related or a duplicate of bug 29536?

Sorry for the delay in follow-up:

Yes, the patch when cherry-picked into a recentish mainline kernel shows noticable improvement.  Subjectively, it still feels a little "chunky" when starting up (I think the login manager and gnome 3 both seem to issue a large number of xrandr requests), but night and day compared to the previous succession of stalls.

w.r.t. bug 29536? I can't say whether it's a dupe or not.  i specifically wasn't getting the periodic stalls every 10-30s.  But perhaps the other reporter had something that was doing xrandr requests with that frequency whereas for me it was only during log-in.

Patch has landed in the 3.4-rc1 kernel, so closing this bug. Thank you all for all the testing and feedback!