[eDP1] 5 second delay between Xorg starting and the greeter starting (Dell Latitude E6410)

Bug #854986 reported by Chris Coulson on 2011-09-20
26
This bug affects 5 people
Affects Status Importance Assigned to Milestone
The Ubuntu Boot Speed Project
High
Unassigned
xf86-video-intel
Confirmed
High
linux (Ubuntu)
High
Unassigned
xserver-xorg-video-intel (Ubuntu)
High
Unassigned

Bug Description

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
.tmp.unity.support.test.0:

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
GraphicsCard:
 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
PccardctlIdent:
 Socket 0:
   no product info available
PccardctlStatus:
 Socket 0:
   no card
PlymouthDebug: Error: [Errno 13] Permission denied: '/var/log/plymouth-debug.log'
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:0.9.5.94+bzr20110919-0ubuntu1~ppa1
version.ia32-libs: ia32-libs N/A
version.libdrm2: libdrm2 2.4.26-1ubuntu1
version.libgl1-mesa-dri: libgl1-mesa-dri 7.11-0ubuntu3
version.libgl1-mesa-dri-experimental: libgl1-mesa-dri-experimental N/A
version.libgl1-mesa-glx: libgl1-mesa-glx 7.11-0ubuntu3
version.xserver-xorg: xserver-xorg 1:7.6+7ubuntu7
version.xserver-xorg-input-evdev: xserver-xorg-input-evdev 1:2.6.0-1ubuntu13
version.xserver-xorg-video-ati: xserver-xorg-video-ati 1:6.14.99~git20110811.g93fc084-0ubuntu1
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

Chris Coulson (chrisccoulson) wrote :
summary: - Xorg takes a long time to start
+ 5 second delay between Xorg starting and the greeter starting (Dell
+ Latitude E6410)

Sorry, this is a better bootchart. The last one was without ureadahead

Chris Coulson (chrisccoulson) wrote :

I instrumented this up a bit, and 2.5s are spent in xf86SetDesiredModes, if that helps

Forwarding this bug from Ubuntu reporter Chris Coulson:

  https://bugs.launchpad.net/ubuntu/+source/xorg-server/+bug/854986

[Problem]
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
.tmp.unity.support.test.0:

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
GraphicsCard:
 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
PccardctlIdent:
 Socket 0:
   no product info available
PccardctlStatus:
 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:0.9.5.94+bzr20110919-0ubuntu1~ppa1
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

Created attachment 51426
BootDmesg.txt

Created attachment 51427
CurrentDmesg.txt

Created attachment 51428
farnsworth-oneiric-20110920-9.png

Created attachment 51429
XorgLog.txt

Created attachment 51430
Xrandr.txt

affects: xorg-server (Ubuntu) → xserver-xorg-video-intel (Ubuntu)
Changed in xserver-xorg-video-intel (Ubuntu):
importance: Undecided → High
status: New → Confirmed
Bryce Harrington (bryce) wrote :

Chris Coulson - I've forwarded this bug upstream to http://bugs.freedesktop.org/show_bug.cgi?id=41057 - please subscribe yourself to this bug, in case they need further information or wish you to test something. Thanks ahead of time!

Changed in xserver-xorg-video-intel (Ubuntu):
status: Confirmed → Triaged
Changed in xserver-xorg-video-intel:
importance: Unknown → Medium
status: Unknown → Confirmed

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.

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.

summary: - 5 second delay between Xorg starting and the greeter starting (Dell
- Latitude E6410)
+ [eDP1] 5 second delay between Xorg starting and the greeter starting
+ (Dell Latitude E6410)
Bryce Harrington (bryce) wrote :

<Sarvatt> did I hear eDP? chrisccoulson, mind trying this kernel? http://kernel.ubuntu.com/~sarvatt/macbook-air/
<Sarvatt> lots of huge delays peppered into the eDP modesetting code trying to make it work right because they didnt know what was going wrong, they're reworking it for 3.2
<chrisccoulson> ah, ok. i'll give that a try

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.

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
modprobe.

Chris Coulson (chrisccoulson) wrote :

So, I tried the kernel from Sarvatt, and it makes an absolutely massive difference - it also fixes the ~5s modprobe issue also present during my boot. The new bootchart is attached

<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 :/

For reference, background on the boot speed analysis in general:
https://wiki.ubuntu.com/DesktopTeam/11.10/BootSpeedAnalysis

Brad Figg (brad-figg) on 2011-09-20
Changed in linux (Ubuntu):
status: New → Confirmed
Bryce Harrington (bryce) on 2011-09-20
tags: added: kernel-handoff-graphics

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.)

Daniel Holbach (dholbach) wrote :

I agree with Chris' comment 6: for me it also makes a massive difference.

Changed in xserver-xorg-video-intel:
importance: Medium → High

Thank you for taking the time to file a bug report on this issue.

However, given the number of bugs that the Kernel Team receives during any development cycle it is impossible for us to review them all. Therefore, we occasionally resort to using automated bots to request further testing. This is such a request.

We have noted that there is a newer version of the development kernel than the one you last tested when this issue was found. Please test again with the newer kernel and indicate in the bug if this issue still exists or not.

If the bug still exists, change the bug status from Incomplete to Confirmed. If the bug no longer exists, change the bug status from Incomplete to Fix Released.

Thank you for your help, we really do appreciate it.

Changed in linux (Ubuntu):
status: Confirmed → Incomplete
tags: added: kernel-request-3.0.0-12.19

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.

Sebastien Bacher (seb128) wrote :

bug #857434 seems similar

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.

Bryce Harrington (bryce) wrote :

Hey chrisccoulson,

Hi, thanks for reporting this issue during the development period of
Ubuntu.

I notice there's not been further comments to the bug report since the
release came out, would you mind updating us on the status of it in the
release?

Are you still able to reproduce the issue? If not, do you think the bug
report can be closed, or do you think we should continue tracking it?

Changed in xserver-xorg-video-intel (Ubuntu):
status: Triaged → Incomplete
Changed in linux (Ubuntu):
importance: Undecided → High
Changed in ubuntu-boot-speed:
status: New → Triaged
importance: Undecided → High
Bryce Harrington (bryce) wrote :

We're closing this bug since it is has been some time with no response from the original bug reporter. However, if the issue still exists in the latest development version of Ubuntu and you are the original reporter please feel free to reopen with the requested information. If you are not the original reporter, please don't reopen this one but instead file a new bug and reference this one.

Changed in xserver-xorg-video-intel (Ubuntu):
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.