Bug 5148 - boot to gdm login speed regression due to pulseaudio timeout on bluetooth service
Summary: boot to gdm login speed regression due to pulseaudio timeout on bluetooth ser...
Status: RESOLVED FIXED
Alias: None
Product: Mageia
Classification: Unclassified
Component: RPM Packages (show other bugs)
Version: Cauldron
Hardware: x86_64 Linux
Priority: Normal normal
Target Milestone: ---
Assignee: Colin Guthrie
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks: 2120 5262
  Show dependency treegraph
 
Reported: 2012-03-28 21:33 CEST by Martin Whitaker
Modified: 2012-04-09 00:33 CEST (History)
2 users (show)

See Also:
Source RPM: gdm
CVE:
Status comment:


Attachments
Extract from /var/log/messages (16.40 KB, text/plain)
2012-03-28 21:35 CEST, Martin Whitaker
Details
output from systemctl show dm.service (2.66 KB, text/plain)
2012-04-06 23:28 CEST, Martin Whitaker
Details
output of systemctl --all --full (40.34 KB, text/plain)
2012-04-06 23:29 CEST, Martin Whitaker
Details

Description Martin Whitaker 2012-03-28 21:33:12 CEST
With a clean install from the Mageia 2 beta 2 DVD on my desktop machine, the elapsed time from leaving the GRUB boot menu to an active GDM login prompt was ~36 seconds, with the switch to the graphics screen occurring at ~33s (I have bootsplash disabled).

After performing a full update 2 days ago, the elapsed time has increased to ~65 seconds, with the switch to the graphics screen still occurring at ~33 seconds. The graphics screen remains blank with just a spinning blue circle of dots under the cursor.

Examining /var/log/messages, the reason seems to be a long timeout delay in pulseaudio, waiting for the org.bluez service. bluetooth.service has previously failed:

Note that my desktop machine has no bluetooth devices.

This occurs on every reboot.

Not sure which package is to blame for this.
Comment 1 Martin Whitaker 2012-03-28 21:35:42 CEST
Created attachment 1879 [details]
Extract from /var/log/messages

I've extracted the relevant section of /var/log/messages. This shows the bluetooth service starting then failing, and pulseaudio reporting a timeout 25 seconds later.
Manuel Hiebel 2012-03-29 14:53:19 CEST

CC: (none) => mageia
Blocks: (none) => 2120
Source RPM: (none) => systemd

Comment 2 Colin Guthrie 2012-04-04 17:49:29 CEST
I've seen this too. I'll certainly get this fixed before release.

Status: NEW => ASSIGNED
Assignee: bugsquad => mageia

Comment 3 Colin Guthrie 2012-04-04 20:58:47 CEST
I did see this, but can you confirm it's still present? I tried to reproduce the error and it seems to have gone... or rather the error is still there but it doesn't seem to cause any harm. Looking back in my logs I've seen the error as far back as 8th March.

I think the reason it's denied is simply due to dbus policy (gdm user is basically not allowed to do all the things a regular user can do). I'm not really too worried about this if it doesn't cause any delays.

So can you check again and see if the problem persists with everything up-to-date?
Comment 4 Martin Whitaker 2012-04-05 01:18:19 CEST
After updating, I no longer get to the GDM login screen at all (although psuedo-ttys are working). Will investigate further tomorrow.
Helge Hielscher 2012-04-06 11:37:22 CEST

CC: (none) => hhielscher

Comment 5 Martin Whitaker 2012-04-06 23:08:01 CEST
Well, I still can't figure out why GDM is not being started on boot, but if I start it manually via

  systemctl start dm.service 


I still see the ~30s delay and the same messages in /var/log/messages
Comment 6 Colin Guthrie 2012-04-06 23:20:36 CEST
Oh you might be suffering from a similar problem to Anssi regarding gdm not starting (or rather dm - he was using kdm, but the same logic applies).

Can you attach "systemctl show dm.service" and "systemctl --all --full" after boot (i.e. when dm fails to start).

As for the gdm bluetooth issue, I'll look into it and see if I can reproduce.
Comment 7 Martin Whitaker 2012-04-06 23:28:39 CEST
Created attachment 1936 [details]
output from systemctl show dm.service
Comment 8 Martin Whitaker 2012-04-06 23:29:21 CEST
Created attachment 1937 [details]
output of systemctl --all --full
Comment 9 Martin Whitaker 2012-04-06 23:31:36 CEST
Thanks Colin. FWIW I have the gdm bluetooth problem on two different machines, one of which has bluetooth hardware, the other does not.
Comment 10 Colin Guthrie 2012-04-06 23:50:01 CEST
OK, so the problem is caused by dbus policy that apparently forbids pulseaudio when run as the gdm user from spawning bluetoothd this then results bluetoothd terminating with a 30s timeout.

You can fix it with an ajustment to the bluez policy file, but this is a bit hacky. I need to work out the *right* way to do it.
Comment 11 Colin Guthrie 2012-04-06 23:53:20 CEST
As a work around for the machine that does have bt hardware, the timeout shouldn't kick in if bluetoothd is already running (i.e. does not need bus activation). If you do: systemctl enable bluetooth.service, that should fix things.

But obviously if bluetoothd is not running for whatever reason, it still shouldn't delay things.
Comment 12 Colin Guthrie 2012-04-06 23:54:20 CEST
Oh and as for the dm.service thing, it appears you do have the same problem as Anssi. Good, at least it's not isolated :D I'll work on that too, I'll split it out into a separate bug.
Colin Guthrie 2012-04-06 23:55:30 CEST

Blocks: (none) => 5262

Comment 13 Colin Guthrie 2012-04-06 23:59:08 CEST
Please see bug #5262 for the prefdm not starting bug.
Comment 14 Colin Guthrie 2012-04-07 00:15:26 CEST
OK, so it seems adding:
 session optional pam_console.so

to gdm-welcome pam.d file will solve the problem.

I'll fix it in gdm, as I need to tweak the pam.d configs there anyway for gnome-keyring.

Source RPM: systemd => gdm

Comment 15 Martin Whitaker 2012-04-07 00:34:09 CEST
Your proposed fix works for me on the machine I've tested it on (the other machine is busy right now).
Comment 16 Colin Guthrie 2012-04-09 00:33:32 CEST
OK, so this should be addressed in latest gdm package.

As you've confirmed that it works, I'll close this bug, but please do feel free to reopen if this is incorrect.

Hopefully we'll get #5262 licked soon too :)
Comment 17 Colin Guthrie 2012-04-09 00:33:59 CEST
Closing as per above comment (forgot to do it then!)

Status: ASSIGNED => RESOLVED
Resolution: (none) => FIXED


Note You need to log in before you can comment on or make changes to this bug.