|Summary:||[eDP] 5 second delay between Xorg starting and the greeter starting (Dell Latitude E6410)|
|Product:||xorg||Reporter:||Bryce Harrington <bryce>|
|Component:||Driver/intel||Assignee:||Eugeni Dodonov <eugeni>|
|Status:||RESOLVED FIXED||QA Contact:||Xorg Project Team <xorg-team>|
|i915 platform:||i915 features:|
|Bug Depends on:|
|Bug Blocks:||42991, 44622|
Description Bryce Harrington 2011-09-20 15:13:33 UTC
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
Comment 2 Bryce Harrington 2011-09-20 15:15:37 UTC
Created attachment 51427 [details] CurrentDmesg.txt
Comment 3 Bryce Harrington 2011-09-20 15:17:02 UTC
Created attachment 51428 [details] farnsworth-oneiric-20110920-9.png
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 modprobe.
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: https://wiki.ubuntu.com/DesktopTeam/11.10/BootSpeedAnalysis
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 <email@example.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 <firstname.lastname@example.org> Reviewed-by: Keith Packard <email@example.com> Tested-by: Sean Finney <firstname.lastname@example.org> Tested-by: Soren Hansen <email@example.com> Tested-by: Hernando Torque <firstname.lastname@example.org> Tested-by: Mike Lothian <email@example.com> Bugzilla: https://bugs.freedesktop.org/show_bug.cgi?id=41059 Signed-off-by: Eugeni Dodonov <firstname.lastname@example.org> Signed-off-by: Dave Airlie <email@example.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.