1755419 - Firefox taking longer to launch

Status: RESOLVED FIXED

(Core :: Widget: Gtk, defect)

Description

[souravgoswami24111997s]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:98.0) Gecko/20100101 Firefox/98.0

Steps to reproduce:

Updated firefox to 64bit 98.0b2 on Linux (Arch) and firefox taking way longer to launch that it did ever before.

The same problem persists in FF 98.0b4.

Actual results:

I'm using an NVME M.2 storage for root partition and SATA III SSD for /home/. Previously firefox just took < 1 second to launch. But now the launching time is no less than 20 seconds.

The problem only occurs after a boot. Once firefox is loaded, even if I kill the process and relaunch, it launches just fine.

Comment 1

[souravgoswami24111997s]

Attachment: strace-10MiB

Here's the 10 MiB strace file, if that helps.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

The Bugbug bot thinks this bug should belong to the 'Core::Widget: Gtk' component, and is moving the bug to that component. Please revert this change in case you think the bot is wrong.

Comment 3

[Martin Stránský [:stransky] (ni? me)]

Please use mozregression to find the broken commit:
https://fedoraproject.org/wiki/How_to_debug_Firefox_problems#Use_Mozregression_tool
Thanks.

Comment 4

[Emilio Cobos Álvarez (:emilio)]

This smells like broken dbus, probably introduced by bug 1734934 or thereabouts? Can you look on your journal for potential D-BUS errors?

Comment 5

[Emilio Cobos Álvarez (:emilio)]

Alternatively, can you paste the output of MOZ_LOG=LookAndFeel:5 /path/to/firefox?

Comment 6

[Emilio Cobos Álvarez (:emilio)]

If comment 4 is right, then the patch above should fix, but we should confirm first.

Comment 7

[Emilio Cobos Álvarez (:emilio)]

Attachment: Bug 1755419 - Don't use default system timeout for settings proxy. r=stransky

Comment 8

[souravgoswami24111997s]

Hi, sorry for late reply. I've tried mozregression, but it didn't detect anything - maybe because as I said, firefox is slow on the first run, and from the 2nd launch, it's normally fast.

I'll debug with MOZ_LOG=LookAndFeel:5 and try to see if I can get any journal messages from dbus-errors.

Comment 9

[souravgoswami24111997s]

Did a journalctl -f and the output is as the following:

Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Activating via systemd: service name='org.freedesktop.portal.Desktop' unit='xdg-desktop-portal.service' requested by ':1.33' (uid=1000 pid=1018 comm="/opt/firefox-developer-edition/firefox ")
Feb 18 23:16:59 archlinux systemd[623]: Starting Portal service...
Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Activating via systemd: service name='org.freedesktop.portal.Documents' unit='xdg-document-portal.service' requested by ':1.35' (uid=1000 pid=1077 comm="/usr/lib/xdg-desktop-portal ")
Feb 18 23:16:59 archlinux systemd[623]: Starting flatpak document portal service...
Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Activating via systemd: service name='org.freedesktop.impl.portal.PermissionStore' unit='xdg-permission-store.service' requested by ':1.36' (uid=1000 pid=1081 comm="/usr/lib/xdg-document-portal ")
Feb 18 23:16:59 archlinux systemd[623]: Starting sandboxed app permission store...
Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Successfully activated service 'org.freedesktop.impl.portal.PermissionStore'
Feb 18 23:16:59 archlinux systemd[623]: Started sandboxed app permission store.
Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Successfully activated service 'org.freedesktop.portal.Documents'
Feb 18 23:16:59 archlinux systemd[623]: Started flatpak document portal service.
Feb 18 23:16:59 archlinux xdg-desktop-por[1077]: No skeleton to export
Feb 18 23:16:59 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Activating via systemd: service name='org.freedesktop.impl.portal.desktop.wlr' unit='xdg-desktop-portal-wlr.service' requested by ':1.35' (uid=1000 pid=1077 comm="/usr/lib/xdg-desktop-portal ")
Feb 18 23:16:59 archlinux systemd[623]: Portal service (wlroots implementation) was skipped because of a failed condition check (ConditionEnvironment=WAYLAND_DISPLAY).
Feb 18 23:17:45 archlinux xdg-desktop-por[1077]: Failed to create screenshot proxy: Error calling StartServiceByName for org.freedesktop.impl.portal.desktop.wlr: Timeout was reached
Feb 18 23:17:45 archlinux xdg-desktop-por[1077]: No skeleton to export
Feb 18 23:18:10 archlinux xdg-desktop-por[1077]: Failed to create screen cast proxy: Error calling StartServiceByName for org.freedesktop.impl.portal.desktop.wlr: Timeout was reached
Feb 18 23:18:10 archlinux xdg-desktop-por[1077]: No skeleton to export
Feb 18 23:18:10 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Successfully activated service 'org.freedesktop.portal.Desktop'
Feb 18 23:18:10 archlinux systemd[623]: Started Portal service.

After some more time, when firefox is already running:

Feb 18 23:19:20 archlinux dbus-daemon[643]: [session uid=1000 pid=643] Failed to activate service 'org.freedesktop.impl.portal.desktop.wlr': timed out (service_start_timeout=120000ms)

Comment 10

[souravgoswami24111997s]

After removing xdg-desktop-portal-wlr package, the problem is fixed.
Actually this problem isn't new. A lot of the apps depending on this package had problem in the past.

https://gitlab.gnome.org/World/gcolor3/-/issues/126

It could be because of the dbus changes?

Comment 11

[souravgoswami24111997s]

(In reply to souravgoswami24111997s from comment #10)

After removing xdg-desktop-portal-wlr package, the problem is fixed.
Actually this problem isn't new. A lot of the apps depending on this package had problem in the past.

https://gitlab.gnome.org/World/gcolor3/-/issues/126

It could be because of the dbus changes?

BTW removing xdg-desktop-portal-wlr with pacman -Rns also removes xdg-desktop-portal.

Here's another one I faced some time ago:
https://github.com/flatpak/xdg-desktop-portal-gtk/issues/332#

Anyway, if I can help by installing the package again. Currently it's an easy fix that doesn't probably provide much insight. But a mere speculation is that it's probably caused by the recent dbus changes as you suspected?

Comment 12

[Emilio Cobos Álvarez (:emilio)]

Yeah, so my patch indeed introduced the issue, by introducing the DBUS query that is timing out. There's not all that much we can do on our end tbh, other than something like comment 7 to prevent startup from taking too long, it's really a misconfiguration on your machine.

Jan, fyi since it seems just installing the wlroots desktop portal implementation can cause this. Do you know how common such misconfiguration can be?

Comment 13

[Jan Alexander Steffens [:heftig]]

This seems to be caused by a long-standing DBus issue where there is no feedback about a failed activation from systemd back to dbus-daemon, so the latter fruitlessly waits for the name to appear. Maybe dbus-broker handles this better?

When installing xdg-desktop-portal, the user is asked to install an implementation. For this prompt, xdg-desktop-portal-gnome is the default choice. I don't think this is a common problem.

Comment 14

[Emilio Cobos Álvarez (:emilio)]

(In reply to Jan Alexander Steffens [:heftig] from comment #13)

This seems to be caused by a long-standing DBus issue where there is no feedback about a failed activation from systemd back to dbus-daemon, so the latter fruitlessly waits for the name to appear. Maybe dbus-broker handles this better?

Curious, do you have a link for this issue? No big deal if not :)

Comment 15

[Jan Alexander Steffens [:heftig]]

(In reply to Emilio Cobos Álvarez (:emilio) from comment #14)

Curious, do you have a link for this issue? No big deal if not :)

Sorry, I thought I remembered something from long ago on the Freedesktop Bugzilla, but I can no longer find it.

Comment 16

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1734934

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/5e045c1de16f
Don't use default system timeout for settings proxy. r=stransky

Comment 18

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/5e045c1de16f

Comment 19

[Pascal Chevrel:pascalc]

Emilio, this is a regression introduced in 98, is that a patch we should uplift to 99 or is that uncommon enough that we can let it ride the trains? Thanks

Comment 20

[Emilio Cobos Álvarez (:emilio)]

Comment on attachment 9264497 [details]
Bug 1755419 - Don't use default system timeout for settings proxy. r=stransky

Beta/Release Uplift Approval Request

• User impact if declined: Slow startup on misconfigured machines.
• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: none
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): Introduces an smaller timeout for startup-critical code.
• String changes made/needed: none

Comment 21

[Pascal Chevrel:pascalc]

Emilio, the patch does not graft cleanly to beta, could you provide a rebased patch? Thanks

Comment 22

[Emilio Cobos Álvarez (:emilio)]

Attachment: Beta patch.

Comment 23

[Pascal Chevrel:pascalc]

Comment on attachment 9265172 [details] [diff] [review]
Beta patch.

Approved for our last 98 beta, thanks!

Comment 24

[Pascal Chevrel:pascalc]

https://hg.mozilla.org/releases/mozilla-beta/rev/88014855bc01