After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 753931 - Login hangs for 90 seconds if toolkit accessibility enabled
Login hangs for 90 seconds if toolkit accessibility enabled
Status: RESOLVED FIXED
Product: at-spi
Classification: Platform
Component: at-spi2-core
unspecified
Other Linux
: Normal major
: ---
Assigned To: At-spi maintainer(s)
At-spi maintainer(s)
Depends on:
Blocks:
 
 
Reported: 2015-08-21 14:01 UTC by Balló György
Modified: 2016-01-26 17:37 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
at-spi-bus-launcher: register with session manager (3.03 KB, patch)
2015-09-15 16:37 UTC, Alberts Muktupāvels
none Details | Review
at-spi-bus-launcher: register with session manager (4.88 KB, patch)
2015-09-18 00:29 UTC, Alberts Muktupāvels
committed Details | Review
Output of GNOME session related to at-spi-dbus-bus.desktop (675 bytes, text/plain)
2015-11-20 10:11 UTC, Balló György
  Details
Output of GNOME Flashback session related to at-spi-dbus-bus.desktop (796 bytes, text/plain)
2015-11-20 10:12 UTC, Balló György
  Details
Output of GNOME session (56.60 KB, text/plain)
2015-11-20 11:33 UTC, Balló György
  Details
Output of GNOME Flashback session (74.60 KB, text/plain)
2015-11-20 11:34 UTC, Balló György
  Details

Description Balló György 2015-08-21 14:01:48 UTC
Steps to reproduce:

1. Make sure that at-spi2-core is installed.

2. Enable toolkit accessibility with the following command:
$ gsettings set org.gnome.desktop.interface toolkit-accessibility true

This enables /etc/xdg/autostart/at-spi-dbus-bus.desktop to autostart in GNOME.

3. Try to relogin, and you'll experience a hang for 90 seconds. In the log, you'll see the following message:
gnome-session[10365]: WARNING: Application 'at-spi-dbus-bus.desktop' failed to register before timeout

I can't reproduce this problem with the GNOME session, only with the GNOME Flashback session.

Package versions:
- at-spi2-core 2.16.0
- gnome-session 3.16.0
- gnome-flashback git master

Distribution: Arch Linux
Comment 1 Alberts Muktupāvels 2015-09-06 22:17:50 UTC
I can not reproduce this on Ubuntu... If enabled then Ubuntu starts at-spi-bus-launcher before gnome-session tries to start it. Since it is already launched by Ubuntu then version started by gnome-session exit as already running and I only see - App at-spi-dbus-bus.desktop exited successfully.

When you say that you can not reproduce with GNOME session, what do you see in log related to at-spi-dbus-bus.desktop? Does it have "App at-spi-dbus-bus.desktop registered" line?

It is started in Initialization phase, it means that it is required that application registers with gnome-session, but I don't see any code that would do that...
Comment 2 Balló György 2015-09-13 12:39:55 UTC
I can see the following lines in log with GNOME Flashback when toolkit-accessibility enabled:

Sep 13 13:49:02 linux gnome-session[709]: Activating service name='org.a11y.atspi.Registry'
Sep 13 13:49:02 linux gnome-session[709]: Successfully activated service 'org.a11y.atspi.Registry'
Sep 13 13:49:02 linux org.a11y.atspi.Registry[736]: SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry
Sep 13 13:50:31 linux gnome-session[709]: WARNING: Application 'at-spi-dbus-bus.desktop' failed to register before timeout

I can see the first three lines even if toolkit-accessibility is disabled.

> If enabled then Ubuntu starts at-spi-bus-launcher before gnome-session tries to start it.

How does Ubuntu launch it?

> When you say that you can not reproduce with GNOME session, what do you see in log related to at-spi-dbus-bus.desktop? Does it have "App at-spi-dbus-bus.desktop registered" line?

I can't see anything related to at-spi-dbus-bus.desktop in log with GNOME session.
Comment 3 Alberts Muktupāvels 2015-09-15 16:09:53 UTC
(In reply to György Balló from comment #2)
> I can see the following lines in log with GNOME Flashback when
> toolkit-accessibility enabled:
> 
> Sep 13 13:49:02 linux gnome-session[709]: Activating service
> name='org.a11y.atspi.Registry'
> Sep 13 13:49:02 linux gnome-session[709]: Successfully activated service
> 'org.a11y.atspi.Registry'
> Sep 13 13:49:02 linux org.a11y.atspi.Registry[736]: SpiRegistry daemon is
> running with well-known name - org.a11y.atspi.Registry
> Sep 13 13:50:31 linux gnome-session[709]: WARNING: Application
> 'at-spi-dbus-bus.desktop' failed to register before timeout
> 
> I can see the first three lines even if toolkit-accessibility is disabled.

I think first three lines is not related to at-spi-bus-launcher.

> > If enabled then Ubuntu starts at-spi-bus-launcher before gnome-session tries to start it.
> 
> How does Ubuntu launch it?

I don't know... Today I saw failed to register, but after doing logout/login app is running before gnome-session... So I have no idea what is going on.

> > When you say that you can not reproduce with GNOME session, what do you see in log related to at-spi-dbus-bus.desktop? Does it have "App at-spi-dbus-bus.desktop registered" line?
> 
> I can't see anything related to at-spi-dbus-bus.desktop in log with GNOME
> session.

Did you start GNOME session with --debug? If not try again... That line is debug line and you will not see it unless gnome-session is started with --debug. Same goes for 'App xxx.desktop exited successfully' message.
Comment 4 Alberts Muktupāvels 2015-09-15 16:37:02 UTC
Created attachment 311389 [details] [review]
at-spi-bus-launcher: register with session manager

This application is started in Initialization phase. In this phase
it is required to register with session manager. See:
https://wiki.gnome.org/Projects/SessionManagement/NewGnomeSession
Comment 5 Alberts Muktupāvels 2015-09-15 16:40:34 UTC
That patch should fix your problem. Please test it, but I still want to know what is in gnome-session log when running GNOME with --debug without this patch.
Comment 6 Alberts Muktupāvels 2015-09-18 00:29:56 UTC
Created attachment 311590 [details] [review]
at-spi-bus-launcher: register with session manager

This application is started in Initialization phase. In this phase
it is required to register with session manager. See:
https://wiki.gnome.org/Projects/SessionManagement/NewGnomeSession
Comment 7 Balló György 2015-11-04 10:51:47 UTC
Strange, but I can't reproduce this problem after I updated GNOME from 3.16 to 3.18.
Comment 8 Balló György 2015-11-07 10:28:37 UTC
Sometimes it still happens with GNOME 3.18, so the patch is probably still needed. Maybe there is a race condition on login?
Comment 9 Alberts Muktupāvels 2015-11-07 15:26:52 UTC
1) If at-spi-bus-launcher is started before gnome-session tries to start it everything will work... because at-spi-bus-launcher is already running and when gnome-session starts it successfully exits with 0. It is treated as successful registration.

https://wiki.gnome.org/Projects/SessionManagement/NewGnomeSession
"In the "Initialization" phase, an application can just exit with status 0 to indicate that it is done setting up."

2) gnome-session is first that tries to start at-spi-bus-launcher. It is started, but it never registers with session manager. gnome-session is waiting for it until it reaches timemout.

I guess I will just reassign this as I think patch is valid in any case. Just wanted to know if this fixes your problem.
Comment 10 Balló György 2015-11-20 10:10:15 UTC
Unfortunately, the patch does not solve the problem. :(

I still always get the same hang on the first login after reboot with GNOME 3.18, even if I apply your patch. I attach the output of `gnome-session --debug` with GNOME and GNOME Flashback.
Comment 11 Balló György 2015-11-20 10:11:42 UTC
Created attachment 315944 [details]
Output of GNOME session related to at-spi-dbus-bus.desktop
Comment 12 Balló György 2015-11-20 10:12:39 UTC
Created attachment 315945 [details]
Output of GNOME Flashback session related to at-spi-dbus-bus.desktop
Comment 13 Alberts Muktupāvels 2015-11-20 10:25:39 UTC
(In reply to György Balló from comment #10)
> Unfortunately, the patch does not solve the problem. :(
> 
> I still always get the same hang on the first login after reboot with GNOME
> 3.18, even if I apply your patch. I attach the output of `gnome-session
> --debug` with GNOME and GNOME Flashback.

WARNING: Application 'at-spi-dbus-bus.desktop' failed to register before timeout
DEBUG(+): App at-spi-dbus-bus.desktop registered

??? Maybe attach full log file?

Also can you update my patch and add extra debug messages?:
1) in main(), before 'if (already_running ())', for example "starting at-spi-bus-launcher"
2) in main(), after 'if (already_running ())', for example "at-spi-bus-launcher is not running, starting."
3) in client_proxy_ready_cb(), before connection to 'g-signal', for example "at-spi-bus-launcher registered with session manager".

Just to make sure you are running patched at-spi-bus-launcher and still it fails to register...
Comment 14 Balló György 2015-11-20 11:33:23 UTC
Created attachment 315956 [details]
Output of GNOME session
Comment 15 Balló György 2015-11-20 11:34:01 UTC
Created attachment 315957 [details]
Output of GNOME Flashback session
Comment 16 Balló György 2015-11-20 11:36:47 UTC
I attached the full log of gnome-session. I added the debug messages also, but I don't know how to get the output of at-spi-bus-launcher, because it's not logged into systemd journal.
Comment 17 Alberts Muktupāvels 2015-11-20 11:44:22 UTC
(In reply to György Balló from comment #16)
> I attached the full log of gnome-session. I added the debug messages also,
> but I don't know how to get the output of at-spi-bus-launcher, because it's
> not logged into systemd journal.

Any chance that you have installed patched version in different location and system is starting non-patched version?

Unfortunately full log did not show anything useful for me...
Comment 18 Balló György 2015-11-20 11:50:13 UTC
(In reply to Alberts Muktupāvels from comment #17)
> Any chance that you have installed patched version in different location and
> system is starting non-patched version?

I replaced the system package, and I can see a debug message when I run at-spi-bus-launcher manually.
Comment 19 Alberts Muktupāvels 2015-12-07 19:26:09 UTC
I got these messages in /var/log/syslog...

I removed ubuntu at-spi2-core package to make sure that it is not started and then started to add some debug messages to at-spi-bus-launcher...

Looking at syslog it looks like it is started twice - by systemd and gnome-session. For me when gnome-session tries to start it, it is already running - previous started instance has added root AT_SPI_BUS property and gnome-session started instance founds this property and exits.

So I commented out exec lines in at-spi-dbus-bus-service.in and org.a11y.Bus.service.in and now I can reproduce this bug - tried 3 times.

Now I applied my patch and all worked - tried more then 3 times. Then I removed my patch and problem is back - tried 2 times. (still with exec lines commented out)

This was tested without restarting pc.

---

I guess you will need to put debug messages and then after each restart when you see this problem try to see why it is taking so long time.
Comment 20 Balló György 2015-12-14 03:39:52 UTC
I don't have /var/log/syslog on my system.

Why is the autostart file needed if at-spi-bus-launcher is started anyway?
Comment 21 Alberts Muktupāvels 2015-12-14 15:50:14 UTC
(In reply to György Balló from comment #20)
> I don't have /var/log/syslog on my system.
> 
> Why is the autostart file needed if at-spi-bus-launcher is started anyway?

I don't know...

https://git.gnome.org/browse/at-spi2-core/commit/bus?id=2a70ba6bf83a675664cda8f68f2d1e815612db53

This commit added back X-GNOME-Autostart-Phase to *.desktop file. In commit message - "I'm also unsure if the .desktop file is still needed, since dbus-daemon should automatically launch the bus launcher on request, but would rather not eliminate it this close to 3.8." So maybe it is not needed anymore.
Comment 22 Alberts Muktupāvels 2016-01-26 12:30:26 UTC
Don't know what changed, but now I can reproduce this every time I login in my JHBuild session. Applying patch fixes problem. Reverting it - problem is back.
Comment 23 Mike Gorse 2016-01-26 14:09:47 UTC
Thanks for the patch.
Pushed to master: d2004d
Comment 24 Alberts Muktupāvels 2016-01-26 14:19:57 UTC
(In reply to Mike Gorse from comment #23)
> Thanks for the patch.
> Pushed to master: d2004d

Thanks!

Any reason why you pushed previous version not the last one? Previous one was incomplete... It will cause 'Not responding' in logout dialog. It needs to respond to session manager that it is ok to end session.

And are you going to push patch also to gnome-3-18 branch?
Comment 25 Mike Gorse 2016-01-26 17:34:29 UTC
(In reply to Alberts Muktupāvels from comment #24)
> (In reply to Mike Gorse from comment #23)
> > Thanks for the patch.
> > Pushed to master: d2004d
> 
> Thanks!
> 
> Any reason why you pushed previous version not the last one? Previous one
> was incomplete... It will cause 'Not responding' in logout dialog. It needs
> to respond to session manager that it is ok to end session.

Sorry. Wasn't careful enough.

> And are you going to push patch also to gnome-3-18 branch?

master: d4ae61
gnome-3-18: 4af5d4