Created attachment 124252 [details] dmesg with drm-intel-nightly (Jun 1 2016) When starting X on the Surface 3, either through starting GDM or a window manager directly, it takes approximately 15-20 seconds for the display to show up after executing the start command, which seems very slow. This might be a duplicate to Bug 93929, but since then the dmesg has gotten much less noisy. It's not clear to me exactly what part of the gpu initialization is taking so long from the logs, there are some gaps of about 2s in logging while the card initializes, but they don't seem to correspond with any one log message.
Xorg.0.log would be relevant as well.
Created attachment 124280 [details] dmesg with timestamps
Created attachment 124281 [details] xorg log with timestamps
I've attached another dmesg and xorg log with matching timestamps, so that they can hopefully be followed together.
> [Thu Jun 2 08:23:21 2016] [Firmware Bug]: battery: (dis)charge rate invalid. Tried removing the battery driver? IIRC that was bogging down on of my CHV machines at some point. That was a long time ago, so might have just been an issue with early firmware. Audio driver was another culprit, but that too was long ago.
I blacklisted that, and several other "noisy" modules (mwifiex_pcie, snd_soc_*), and did not seem to help. I'll update the xorg log and dmesg.
Created attachment 124283 [details] dmesg with timestamps, after blacklist
Created attachment 124284 [details] xorg log with timestamps, after blacklist
Hmm, just happens the last thing in the log before the pause is libinput, then logind transferring a bunch of fd. Maybe Section "ServerFlags" Option "NoAutoAddDevices" EndSection ? You won't have any input unless you manually add one, but for a quick test of whether it starts any quicker may be worthwhile if you have a remote login. Or running Xorg under strace -f -tt and see if there is a long wait for a device.
(In reply to Chris Wilson from comment #9) > Maybe > > Section "ServerFlags" > Option "NoAutoAddDevices" > EndSection I tried this, and X didn't come up any faster. Will attach another log pair.
Created attachment 124285 [details] dmesg, Comment 10
Created attachment 124286 [details] xorg log, Comment 10
The logs more or less say nothing is happening. You see the same delay when launching X with startx? Could you use drm.debug=0xf (so we have atomics and ioctls) then $ echo -e "\nstartx\n" > /dev/kmsg $ startx ... in a terminal or whatever: $ echo -e "\nhello world\n" > /dev/ksmg just so we have timestamps on everything. You may need to increase the dmesg logbuffer size.
Actually, "startx" seems to be pretty immediate, it's just starting gdm that's really really slow. I've got a dmesg for each case. In the gdm case, there are several second breaks above some drm_stob_open calls... In the "startx" case that just launches twm, there are no large breaks in logging. Search for "startx" as suggested. (With gdm, I switched back to a VT to add the "hello world" log.)
Created attachment 124289 [details] dmesg, gdm, comment 14
Created attachment 124290 [details] dmesg, startx, comment 14
There are some long delays in there (setgama > 0.5s, getconnector > 0.2s), but the pauses do not correlate with device or driver activity. I can confidently say userspace is just being slow. Maybe stalling for disk?
(In reply to Chris Wilson from comment #17) > There are some long delays in there (setgama > 0.5s, getconnector > 0.2s), > but the pauses do not correlate with device or driver activity. I can > confidently say userspace is just being slow. Maybe stalling for disk? It's possible. I tried caching all of /bin and /lib in memory prior to starting GDM (using vmtouch) and it did bring the delay down to approx 10s, and I am using a slow disk. If you guys are confident that this is just the result of a slow disk, then I must apologize for the noise. Thanks for your help!
Perhaps "perf timechart"? That's certainly a tool I wish got move love.
Created attachment 124309 [details] perf timechart output I'm not totally sure I'm reading the output correctly, but as far as I can tell, from the point where GDM is launched until when it shows up on screen, there is pretty much constant disk IO.
Yes, it does look that way. stracing the suspects may reveal a clue in the pattern of syscall that are slow (which files etc), or investigate the blktrace output, I wonder if that will you tell which driver is blocking and why. More than likely it is one slow device clogging the queues. Or the disk-io is just a red herring.
I installed to a faster medium, and now GDM starts almost immediately. So, it seems like it was just a slow disk after all.
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.