Bug 41057 - [eDP] 5 second delay between Xorg starting and the greeter starting (Dell Latitude E6410)
Summary: [eDP] 5 second delay between Xorg starting and the greeter starting (Dell Lat...
Alias: None
Product: xorg
Classification: Unclassified
Component: Driver/intel (show other bugs)
Version: 7.6 (2010.12)
Hardware: x86-64 (AMD64) Linux (All)
: high major
Assignee: Eugeni Dodonov
QA Contact: Xorg Project Team
Depends on:
Blocks: 42991 44622
  Show dependency treegraph
Reported: 2011-09-20 15:13 UTC by Bryce Harrington
Modified: 2012-04-02 10:57 UTC (History)
1 user (show)

See Also:
i915 platform:
i915 features:

BootDmesg.txt (55.38 KB, text/plain)
2011-09-20 15:15 UTC, Bryce Harrington
no flags Details
CurrentDmesg.txt (4.04 KB, text/plain)
2011-09-20 15:15 UTC, Bryce Harrington
no flags Details
farnsworth-oneiric-20110920-9.png (291.85 KB, image/png)
2011-09-20 15:17 UTC, Bryce Harrington
no flags Details
XorgLog.txt (27.82 KB, text/plain)
2011-09-20 15:17 UTC, Bryce Harrington
no flags Details
Xrandr.txt (3.15 KB, text/plain)
2011-09-20 15:17 UTC, Bryce Harrington
no flags Details
drm debug output hp2540p Fedora16 3.1.6 (204.68 KB, text/plain)
2011-12-28 06:55 UTC, Wolfgang Breyha
no flags Details

Description Bryce Harrington 2011-09-20 15:13:33 UTC
Forwarding this bug from Ubuntu reporter Chris Coulson:


Output probing is traced to causing a multi-second delay during boot.

Some experimentation by the reporter and others seeing same/similar issues show that by forcing off disconnected outputs, the boot speed is significantly improved.

[Original Report]
I've been looking at our session startup time this week, and I've got one of the big delays right down already (bug 854101). However, the next biggest offender is Xorg (when starting a 2d session) - there appears to be a ~5s delay between Xorg starting and the greeter loading.

You can see this in the bootchart attached.

Looking at the timestamps in my Xorg.0.log shows a pretty big delay just here:

[ 15.583] (II) intel(0): Initializing HW Cursor
[ 18.030] (II) intel(0): RandR 1.2 enabled, ignore the following RandR disabled message.

18 seconds matches up perfectly on the bootchart with the lightdm greeter starting.

ProblemType: Bug
DistroRelease: Ubuntu 11.10
Package: xserver-xorg 1:7.6+7ubuntu7
ProcVersionSignature: Ubuntu 3.0.0-11.18-generic 3.0.4
Uname: Linux 3.0.0-11-generic x86_64

ApportVersion: 1.23-0ubuntu1
Architecture: amd64
CompizPlugins: [core,bailer,detection,composite,opengl,compiztoolbox,decor,vpswitch,regex,snap,move,resize,gnomecompat,mousepoll,grid,place,imgpng,unitymtgrabhandles,animation,session,workarounds,wall,fade,scale,expo,ezoom,unityshell]
CompositorRunning: None
Date: Tue Sep 20 19:58:36 2011
DistUpgraded: Fresh install
DistroCodename: oneiric
DistroVariant: ubuntu
ExtraDebuggingInterest: Yes, whatever it takes to get this fixed in Ubuntu
 Intel Corporation Core Processor Integrated Graphics Controller [8086:0046] (rev 02) (prog-if 00 [VGA controller])
   Subsystem: Dell Device [1028:040a]
InstallationMedia: Ubuntu 11.10 "Oneiric Ocelot" - Beta amd64 (20110901)
MachineType: Dell Inc. Latitude E6410
 Socket 0:
   no product info available
 Socket 0:
   no card
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.0.0-11-generic root=UUID=b2e419c9-361b-45c5-8964-3ee8ca387122 ro quiet splash vt.handoff=7
SourcePackage: xorg
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 02/15/2011
dmi.bios.vendor: Dell Inc.
dmi.bios.version: A07
dmi.board.name: 04373Y
dmi.board.vendor: Dell Inc.
dmi.board.version: A03
dmi.chassis.type: 9
dmi.chassis.vendor: Dell Inc.
dmi.modalias: dmi:bvnDellInc.:bvrA07:bd02/15/2011:svnDellInc.:pnLatitudeE6410:pvr0001:rvnDellInc.:rn04373Y:rvrA03:cvnDellInc.:ct9:cvr:
dmi.product.name: Latitude E6410
dmi.product.version: 0001
dmi.sys.vendor: Dell Inc.
version.compiz: compiz 1:
version.libdrm2: libdrm2 2.4.26-1ubuntu1
version.xserver-xorg: xserver-xorg 1:7.6+7ubuntu7
version.xserver-xorg-video-intel: xserver-xorg-video-intel 2:2.15.901-1ubuntu2
version.xserver-xorg-video-nouveau: xserver-xorg-video-nouveau 1:0.0.16+git20110411+8378443-1
Comment 1 Bryce Harrington 2011-09-20 15:15:23 UTC
Created attachment 51426 [details]
Comment 2 Bryce Harrington 2011-09-20 15:15:37 UTC
Created attachment 51427 [details]
Comment 3 Bryce Harrington 2011-09-20 15:17:02 UTC
Created attachment 51428 [details]
Comment 4 Bryce Harrington 2011-09-20 15:17:17 UTC
Created attachment 51429 [details]
Comment 5 Bryce Harrington 2011-09-20 15:17:30 UTC
Created attachment 51430 [details]
Comment 6 Bryce Harrington 2011-09-20 15:37:21 UTC
I had Chris disable disconnected outputs via his /etc/X11/xorg.conf, which brought probing time from  ~0.5s to ~0.13s, however it did not affect the Xorg startup time (still ~5sec).  Then, having him connect an external monitor and disable eDP1 brought the startup time down to ~3.6 sec.

<chrisccoulson> the other big delay seems to be here:
<chrisccoulson> [    11.508] drmOpenDevice: open result is 12, (OK)
<chrisccoulson> [    13.231] drmOpenByBusid: Searching for BusID pci:0000:00:02.0

Not sure what to make of that.
Comment 7 Bryce Harrington 2011-09-20 15:44:09 UTC
User says this is a recently purchased machine; the issue is not known to be a regression.

At XDC, Keith Packard indicated that eDP was difficult to support; I'm assuming that's what's to blame here.
Comment 8 Chris Wilson 2011-09-20 15:51:38 UTC
Let's attack this one as being the slightly easy of the two, and hopefully should give some insight into the pair.

Can we get an strace of X starting along with a perf report? Something like strace -t -o x.strace X -ac
perf record -f -g -a X -ac && perf report | cat > x.perf

And see if we capture any obvious clues.
Comment 9 Bryce Harrington 2011-09-20 15:57:25 UTC
We had Chris also test the kernel at
http://kernel.ubuntu.com/~sarvatt/macbook-air/, which is keithp's reworking of
eDP modesetting.

This brought it down to ~2sec with eDP enabled, and also fixed a ~5sec
Comment 10 Bryce Harrington 2011-09-20 16:12:53 UTC
<chrisccoulson> bryceh, ah, this is going to be fun. that drm delay only happens at startup, so i can't just run another xserver manually with strace :/
Comment 11 Bryce Harrington 2011-09-20 16:28:58 UTC
Possibly this is a dupe of https://bugs.freedesktop.org/show_bug.cgi?id=39533#c67 ?
Comment 12 Bryce Harrington 2011-09-20 16:33:04 UTC
For reference, background on the boot speed analysis in general:
Comment 13 Chris Wilson 2011-09-21 01:35:06 UTC
Ok, eDP has quite a few spurious and long delays that hopefully can be replaced with the shorter delays in the correct places that Keith is working on. I think having adding initcall_debug along with a builtin i915.ko will be most useful then. (That iirc gives the times of each function entry/exit.)
Comment 14 Eugeni Dodonov 2011-09-27 14:31:15 UTC
Also, perhaps it could be related to bug #41059 too? Could you please try with the patches attached to that bug?

One of them should fix the problem directly in i915 driver. Another relies on more advanced bit testing carried out by i2c_algo_bit. Both has reduced the display detection delay greatly in my case - from over 4s to 0.366s in the worst case.
Comment 15 Eugeni Dodonov 2011-10-18 04:02:05 UTC
There was no feedback on my question :), but the patch in question which should fix both this and bug #41059 has landed into intel-gfx mailing list.
Comment 16 Wolfgang Breyha 2011-12-28 06:53:59 UTC
I've the same issues on my HP EliteBook 2540p with Intel Arrandale
00:02.0 0300: 8086:0046 

I had Fedora 14 installed and it worked up to 2.6.35 pretty fast (SSD inside). Now on F16 with kernel 3.1.0-3.1.6 EDID readouts are very slow. This starts when kernel sets mode and continues when X starts. I get a boot penalty of about 20 seconds because X starts several readouts both for login screen and X session afterwards. Screenupdates are blocked and mouse is not movable in this time.

I activated drm debugging as stated in bug #41059 and I see that the readout of the Laptop Display connected to eDP-1 is pretty slow:
Dec 28 00:15:55 hpwb kernel: [    9.893404] [drm:drm_mode_getconnector], [CONNECTOR:5:?]
Dec 28 00:15:55 hpwb kernel: [    9.893409] [drm:drm_helper_probe_single_connector_modes], [CONNECTOR:5:eDP-1]
Dec 28 00:15:55 hpwb kernel: [    9.893415] [drm:intel_dp_detect], DPCD: 110a810100000100
Dec 28 00:15:55 hpwb kernel: [    9.895541] [drm:i2c_algo_dp_aux_xfer], dp_aux_xfer return 2
Dec 28 00:15:55 hpwb kernel: [    9.961556] [drm:i2c_algo_dp_aux_xfer], dp_aux_xfer return 2
Dec 28 00:15:55 hpwb kernel: [   10.563935] [drm:i2c_algo_dp_aux_xfer], dp_aux_xfer return 2
Dec 28 00:15:55 hpwb kernel: [   10.629955] [drm:i2c_algo_dp_aux_xfer], dp_aux_xfer return 2
Dec 28 00:15:55 hpwb kernel: [   11.230428] [drm:drm_helper_probe_single_connector_modes], [CONNECTOR:5:eDP-1] probed modes :
Dec 28 00:15:55 hpwb kernel: [   11.230434] [drm:drm_mode_debug_printmodeline], Modeline 20:"1280x800" 60 69300 1280 1320 1348 1418 800 802 806 814 0x48 0xa
Dec 28 00:15:55 hpwb kernel: [   11.230441] [drm:drm_mode_debug_printmodeline], Modeline 25:"1280x800" 40 46200 1280 1320 1348 1418 800 802 806 814 0x40 0xa
Dec 28 00:15:55 hpwb kernel: [   11.230459] [drm:drm_mode_getconnector], [CONNECTOR:5:?]

The disconnected pins are not that slow on the other hand. Not sure if the fixes from bug #41059 speed things up, but 'll try to build a kernel with them.

I'll attach my complete "grep drm kernel.log" from yesterday.
Comment 17 Wolfgang Breyha 2011-12-28 06:55:39 UTC
Created attachment 54899 [details]
drm debug output hp2540p Fedora16 3.1.6
Comment 18 Chris Wilson 2012-02-24 08:44:15 UTC
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
    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.
Comment 19 Eugeni Dodonov 2012-04-02 10:57:03 UTC
I am pretty sure that the problem here was fixed with the patch Chris Wilson mentioned, and with all other eDP-related patches in 3.4-rc1.

But if it still that bad, please, feel free to reopen so we could investigate it further.

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.