Closed Bug 1862159 Opened 1 year ago Closed 2 months ago

[Linux] D-Bus wake lock mechanism malfunctions if Firefox is open for an extended period of time

Categories

(Core :: Widget: Gtk, defect, P3)

Product:
Core
Component:
Widget: Gtk
Platform:
Desktop
Linux
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
121 Branch
Tracking Flags:
Tracking Status
firefox121 --- wontfix
firefox143 --- wontfix
firefox144 --- fixed

People

(Reporter: TheDcoder, Assigned: stransky)

References

(Blocks 1 open bug)

Details

Attachments

(9 files)

output.log
6.99 KB, text/plain
Details
Bug 1862159 [Linux] Add IsCancelledGError() to detect DBus operation cancellation r?emilio
48 bytes, text/x-phabricator-request
Details | Review
Bug 1862159 [Linux] Rework wake lock to better handle wake lock states and allow to cancel pending DBus operations r?emilio
48 bytes, text/x-phabricator-request
Details | Review
Bug 1862159 [Linux] Fix WakeLockListener to build with disabled DBus r?emilio
48 bytes, text/x-phabricator-request
Details | Review
firefox_no_inhibit
10.00 KB, text/plain
Details
LinuxWakeLock.log
64.04 KB, text/plain
Details
MOZ_LOG="LinuxWakeLock:5" firefox &> firefox.log
7.18 KB, text/plain
Details
firefox_first_part_inhibitor_working.log
463.20 KB, text/plain
Details
Bug 1862159 - Fix WakeLockTopic state on DBus uninhibit failure r?stransky
48 bytes, text/x-phabricator-request
Details | Review

Firefox fails to properly call the org.freedesktop.PowerManagement D-Bus interface. The issue was originally posted on Xfce's bug-tracker:

I've been doing some debugging and found that Firefox isn't calling the D-Bus interface method at org.freedesktop.PowerManagement.Inhibit -> Inhibit.

I used this command to monitor the calls and didn't see anything while I was playing media in Firefox: busctl --user monitor org.freedesktop.PowerManagement

The interesting thing is that it does call org.freedesktop.PowerManagement.Inhibit -> UnInhibit with the wrong cookie value every-time I pause the video, but it won't call Inhibit after I resume playback:

$ busctl --user monitor org.freedesktop.PowerManagement
Monitoring bus message stream.
‣ Type=method_call  Endian=l  Flags=0  Version=1 Cookie=2768  Timestamp="Tue 2023-10-31 06:41:08.423673 UTC"
  Sender=:1.43  Destination=:1.35  Path=/org/freedesktop/PowerManagement/Inhibit  Interface=org.freedesktop.PowerManagement.Inhibit  Member=UnInhibit
  UniqueName=:1.43
  MESSAGE "u" {
          UINT32 21;
  };

‣ Type=error  Endian=l  Flags=1  Version=1 Cookie=273  ReplyCookie=2768  Timestamp="Tue 2023-10-31 06:41:08.423829 UTC"
  Sender=:1.35  Destination=:1.43
  ErrorName=org.xfce.PowerManager.Error.CookieNotFound  ErrorMessage="Invalid cookie"
  UniqueName=:1.35
  MESSAGE "s" {
          STRING "Invalid cookie";
  };

‣ Type=method_call  Endian=l  Flags=0  Version=1 Cookie=2777  Timestamp="Tue 2023-10-31 06:41:15.928327 UTC"
  Sender=:1.43  Destination=:1.35  Path=/org/freedesktop/PowerManagement/Inhibit  Interface=org.freedesktop.PowerManagement.Inhibit  Member=UnInhibit
  UniqueName=:1.43
  MESSAGE "u" {
          UINT32 21;
  };

‣ Type=error  Endian=l  Flags=1  Version=1 Cookie=274  ReplyCookie=2777  Timestamp="Tue 2023-10-31 06:41:15.928471 UTC"
  Sender=:1.35  Destination=:1.43
  ErrorName=org.xfce.PowerManager.Error.CookieNotFound  ErrorMessage="Invalid cookie"
  UniqueName=:1.35
  MESSAGE "s" {
          STRING "Invalid cookie";
  };

‣ Type=method_call  Endian=l  Flags=0  Version=1 Cookie=2786  Timestamp="Tue 2023-10-31 06:41:25.629256 UTC"
  Sender=:1.43  Destination=:1.35  Path=/org/freedesktop/PowerManagement/Inhibit  Interface=org.freedesktop.PowerManagement.Inhibit  Member=UnInhibit
  UniqueName=:1.43
  MESSAGE "u" {
          UINT32 21;
  };

‣ Type=error  Endian=l  Flags=1  Version=1 Cookie=275  ReplyCookie=2786  Timestamp="Tue 2023-10-31 06:41:25.629365 UTC"
  Sender=:1.35  Destination=:1.43
  ErrorName=org.xfce.PowerManager.Error.CookieNotFound  ErrorMessage="Invalid cookie"
  UniqueName=:1.35
  MESSAGE "s" {
          STRING "Invalid cookie";
  };

I also found that this issue is not easily reproducible. I restarted Firefox to test it again and it worked perfectly and called both functions normally with the correct values!

I normally keep Firefox open 24/7, so at some point it glitches out and stops calling Inhibit and keeps calling UnInhibit with a cached cookie value every time the playback is paused.

So this is almost certainly a regression in Firefox itself, will do some more digging and get back with the results here.

This is on a X11 desktop running Firefox v119, but the issue might have been present in older versions as well. The most recent change which touches the part of this D-Bus code is bug 1848084 (credit to bbhtt from Libera IRC for finding this).

I will continue to narrow down the steps required to reproduce this bug, if anyone has any clues please let me know. I use Firefox with several windows (including private windows) with at-least one window being always open at a time.

Component: General → Widget: Gtk
Product: Firefox → Core

Can you run with MOZ_LOG="LinuxWakeLock:5" env variable? You'll get wake lock log from Firefox perspective and it's see what's called.

Flags: needinfo?(TheDcoder)
Attached file output.log —
Turns out it was actually very easy to reproduce: 1. Open Firefox 2. Open private window and load a video (I just opened YouTube) 4. Close the private window 5. Open a new private window and load another video 6. Confirm that power inhibition is broken Here's the terminal output:

Turns out it was actually very easy to reproduce:

  1. Open Firefox
  2. Open private window and load a video (I just opened YouTube)
  3. Close the private window
  4. Open a new private window and load another video
  5. Confirm that power inhibition is broken

Here's the terminal output:

$ MOZ_LOG="LinuxWakeLock:5" firefox
[GFX1-]: vaapitest: ManageChildProcess failed

[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockListener video-playing state locked-foreground
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 330129: Main Thread]: D/LinuxWakeLock   switched to WakeLockType FreeDesktopScreensaver
[Parent 330129: Main Thread]: D/LinuxWakeLock shouldLock 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::InhibitScreensaver() state 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 330129: Main Thread]: D/LinuxWakeLock InhibitFreeDesktopScreensaver()
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitScreensaver() waiting 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitFailed(1)
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopScreensaver
[Parent 330129: Main Thread]: D/LinuxWakeLock   switched to WakeLockType FreeDesktopPower
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 330129: Main Thread]: D/LinuxWakeLock InhibitFreeDesktopPower()
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitScreensaver() waiting 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 3
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockListener video-playing state locked-background
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::~WakeLockTopic() state 0
[Parent 330129: Main Thread]: D/LinuxWakeLock shouldLock 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::UninhibitScreensaver() state 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 330129: Main Thread]: D/LinuxWakeLock UninhibitFreeDesktopPower()
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitScreensaver() waiting 0 request id 3
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockListener video-playing state unlocked
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::~WakeLockTopic() state 0
[Parent 330129: Main Thread]: D/LinuxWakeLock shouldLock 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::UninhibitScreensaver() state 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 330129: Main Thread]: D/LinuxWakeLock UninhibitFreeDesktopPower()
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitScreensaver() waiting 1 request id 3
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitFailed() UnInhibit call failed : GDBus.Error:org.xfce.PowerManager.Error.CookieNotFound: Invalid cookie
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitFailed()
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376ee00 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachine.cpp:372
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376ee00 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006) - static MP4Metadata::ResultAndByteBuffer mozilla::MP4Metadata::Metadata(ByteStream *): Cannot parse metadata: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachineBase.cpp:166
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376dc00 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachine.cpp:372
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376dc00 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006) - static MP4Metadata::ResultAndByteBuffer mozilla::MP4Metadata::Metadata(ByteStream *): Cannot parse metadata: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachineBase.cpp:166
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376e800 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachine.cpp:372
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376e800 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006) - static MP4Metadata::ResultAndByteBuffer mozilla::MP4Metadata::Metadata(ByteStream *): Cannot parse metadata: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachineBase.cpp:166
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376e200 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachine.cpp:372
[Child 330414, MediaDecoderStateMachine #1] WARNING: Decoder=7f5d0376e200 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006) - static MP4Metadata::ResultAndByteBuffer mozilla::MP4Metadata::Metadata(ByteStream *): Cannot parse metadata: file /build/firefox/src/firefox-119.0/dom/media/MediaDecoderStateMachineBase.cpp:166
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockListener video-playing state locked-foreground
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::~WakeLockTopic() state 0
[Parent 330129: Main Thread]: D/LinuxWakeLock shouldLock 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::InhibitScreensaver() state 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockListener video-playing state unlocked
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::~WakeLockTopic() state 0
[Parent 330129: Main Thread]: D/LinuxWakeLock shouldLock 0
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::UninhibitScreensaver() state 1
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 330129: Main Thread]: D/LinuxWakeLock UninhibitFreeDesktopPower()
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitScreensaver() waiting 0 request id 3
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitFailed() UnInhibit call failed : GDBus.Error:org.xfce.PowerManager.Error.CookieNotFound: Invalid cookie
[Parent 330129: Main Thread]: D/LinuxWakeLock WakeLockTopic::DBusUninhibitFailed()
[Socket 330231: Main Thread]: D/LinuxWakeLock WakeLockListener::Shutdown()
Flags: needinfo?(TheDcoder)

This testcase works for me, Thanks!

Flags: needinfo?(stransky)
Flags: needinfo?(stransky)
Priority: -- → P3
Assignee: nobody → stransky
Status: UNCONFIRMED → ASSIGNED
Ever confirmed: true
  • Update WAKE_LOCK_LOG to print 'this' which allows to sort operations by lock type
  • GetOrInsertNew() call always creates a new WakeLockTopic object so in this patch call it only if we create a new object.
  • Split mWaitingForDBusReply to mWaitingForDBusInhibit/mWaitingForDBusUninhibit. It allows to ignore repeated requests and also cancel
    opposite requests.
  • Use g_cancellable to cancel pending DBus operation if we want different wake lock action.

Depends on D192621

Pushed by stransky@redhat.com: https://hg.mozilla.org/integration/autoland/rev/a3014ce3c54a [Linux] Add IsCancelledGError() to detect DBus operation cancellation r=emilio

https://hg.mozilla.org/mozilla-central/rev/a3014ce3c54a

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
status-firefox121: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 121 Branch

(In reply to Sandor Molnar[:smolnar] from comment #8)

https://hg.mozilla.org/mozilla-central/rev/a3014ce3c54a

Are you sure that this is fixed? Revision D192622 also seems to be required and it's still open for merge.

Also would these fixes be deployed in v121? Why not v120?

Status: RESOLVED → VERIFIED
Flags: needinfo?(smolnar)

Sorry, my fault. Forget to mark as leave open.

Status: VERIFIED → REOPENED
Flags: needinfo?(smolnar)
Resolution: FIXED → ---
Status: REOPENED → ASSIGNED

I'm testing firefox-nightly installed from here https://aur.archlinux.org/cgit/aur.git/tree/PKGBUILD?h=firefox-nightly-bin

This isn't fixed.

# busctl --user monitor org.freedesktop.PowerManagement

‣ Type=method_call  Endian=l  Flags=0  Version=1 Cookie=172  Timestamp="Tue 2023-11-07 19:04:09.075478 UTC"
  Sender=:1.110  Destination=:1.26  Path=/org/freedesktop/PowerManagement/Inhibit  Interface=org.freedesktop.PowerManagement.Inhibit  Member=UnInhibit
  UniqueName=:1.110
  MESSAGE "u" {
          UINT32 2;
  };

‣ Type=error  Endian=l  Flags=1  Version=1 Cookie=383  ReplyCookie=172  Timestamp="Tue 2023-11-07 19:04:09.075756 UTC"
  Sender=:1.26  Destination=:1.110
  ErrorName=org.xfce.PowerManager.Error.CookieNotFound  ErrorMessage="Invalid cookie"
  UniqueName=:1.26
  MESSAGE "s" {
          STRING "Invalid cookie";
  };

We're waiting to D192622.

Blocks: wakelock
Pushed by stransky@redhat.com: https://hg.mozilla.org/integration/autoland/rev/7c1e05f847ba [Linux] Rework wake lock to better handle wake lock states and allow to cancel pending DBus operations r=emilio

Backed out for causing WakeLock related failures.

Flags: needinfo?(stransky)

Updated, Thanks.

Flags: needinfo?(stransky)
Pushed by stransky@redhat.com: https://hg.mozilla.org/integration/autoland/rev/63c54b25b36f [Linux] Rework wake lock to better handle wake lock states and allow to cancel pending DBus operations r=emilio

Backed out for causing bp-nu bustages in WakeLockListener.h.

  • Backout link
  • Push with failures
  • Failure Log
  • Failure line: /builds/worker/checkouts/gecko/widget/gtk/WakeLockListener.h:46:53: error: implicit instantiation of undefined template 'nsRefCountedHashtable<nsStringHashKey, RefPtr<WakeLockTopic>>'
Flags: needinfo?(stransky)

Updated, Thanks.

Flags: needinfo?(stransky)
Pushed by stransky@redhat.com: https://hg.mozilla.org/integration/autoland/rev/61e218fa6f1c [Linux] Rework wake lock to better handle wake lock states and allow to cancel pending DBus operations r=emilio
Pushed by stransky@redhat.com: https://hg.mozilla.org/integration/autoland/rev/7d108376e269 [Linux] Fix WakeLockListener to build with disabled DBus r=emilio

https://hg.mozilla.org/mozilla-central/rev/61e218fa6f1c
https://hg.mozilla.org/mozilla-central/rev/7d108376e269

Status: ASSIGNED → RESOLVED
Closed: 1 year ago → 1 year ago
status-firefox121: affected → fixed
Resolution: --- → FIXED

Is this supposed to be fixed? I can still reproduce it in Nightly 121.0a1 (2023-11-10) (64-bit)

Flags: needinfo?(stransky)

(In reply to Damon from comment #23)

Is this supposed to be fixed? I can still reproduce it in Nightly 121.0a1 (2023-11-10) (64-bit)

Yes, it should be fixed. Please attach another log of MOZ_LOG="LinuxWakeLock:5".
Thanks.

Flags: needinfo?(stransky) → needinfo?(TheDcoder)

The steps to reproduce have changed a bit:

  1. Open Firefox
  2. Open a private window and load a video
  3. Close the window abruptly (without pausing/stopping the video, while it's still playing)
  4. Repeat step 2
  5. Confirm that power inhibition is broken

Output:

$ MOZ_LOG="LinuxWakeLock:5" firefox-nightly
[GFX1-]: vaapitest: ManageChildProcess failed

[Parent 70035, Main Thread] WARNING: Failed to call GetIdletime(): GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.Mutter.IdleMonitor was not provided by any .service files
: 'glib warning', file /build/firefox-nightly/src/mozilla-central/toolkit/xre/nsSigHandlers.cpp:187

** (firefoxnightly:70035): WARNING **: 00:39:29.405: Failed to call GetIdletime(): GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.Mutter.IdleMonitor was not provided by any .service files

[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::WakeLockTopic() created video-playing
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580]   switched to WakeLockType FreeDesktopScreensaver
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] InhibitFreeDesktopScreensaver()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitFailed(1)
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopScreensaver
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580]   switched to WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] InhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 11 mShouldInhibit 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] UninhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 request id 11
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitSucceeded() mShouldInhibit 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] InhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 16 mShouldInhibit 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state locked-background request lock 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] UninhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 request id 16
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] UninhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 1 request id 16
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580]   already waiting to uninihibit, return
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitFailed() UnInhibit call failed : GDBus.Error:org.xfce.PowerManager.Error.CookieNotFound: Invalid cookie
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitFailed()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::InhibitScreensaver() Inhibited 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] UninhibitFreeDesktopPower()
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::DBusUninhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 request id 0
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580]   missing inihibit token, quit.
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f30c22fd8e0] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 70035: Main Thread]: D/LinuxWakeLock [7f308ea77580] WakeLockTopic::InhibitScreensaver() Inhibited 1
Flags: needinfo?(TheDcoder)
Status: RESOLVED → REOPENED
Resolution: FIXED → ---
Attached file firefox_no_inhibit —

This bug is still present on Firefox 122.0.1, Arch Linux. Relevant package versions:
linux 6.7.4.arch1-1
dbus 1.14.10-2
firefox 122.0.1-1

Comment on attachment 9380085 [details]
firefox_no_inhibit

I am using i3wm 4.23, no desktop environment.

Can confirm, this bug is still happening.

Archlinux up-to-date. XFCE.

Around 6 months ago, I was experiencing similar issues when Firefox would randomly stop inhibiting screensaver after some time, closing/opening tabs or just starting/stopping playback in more than two tabs (concurrently or sequentially).

Recently, with versions ~120 screensaver/lock inhibition stopped working completely.

I tested on Ubuntu-Mate 22.04, 23.10, 24.04 and vanilla Ubuntu 24.04 and the problem persists.
Firefox packages from Mozilla, Canonical PPA and Snap are all broken.

Here is the log of setting the lock to 1 minute, starting playback, waiting till screensaver actiavtes, cancel the the screensaver and stop playback:

MOZ_LOG="LinuxWakeLock:5" firefox
libva info: VA-API version 1.19.0
libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_18
libva info: va_openDriver() returns 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::WakeLockTopic() created video-playing
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] InhibitFreeDesktopScreensaver()
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed(1)
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] InhibitFreeDesktopPower()
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.PowerManagement was not provided by any .service files
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed(1)
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal(): inhibited, objpath to unihibit: /org/freedesktop/portal/desktop/request/1_111/t
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 0 mShouldInhibit 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 object path: /org/freedesktop/portal/desktop/request/1_111/t
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusUninhibitSucceeded() mShouldInhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitFreeDesktopPortal() Inhibit removed

And this the log of simple start playback, stop playback

[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal(): inhibited, objpath to unihibit: /org/freedesktop/portal/desktop/request/1_111/t/1041562613

(In reply to Eugene San from comment #29)

Around 6 months ago, I was experiencing similar issues when Firefox would randomly stop inhibiting screensaver after some time, closing/opening tabs or just starting/stopping playback in more than two tabs (concurrently or sequentially).

Recently, with versions ~120 screensaver/lock inhibition stopped working completely.

I tested on Ubuntu-Mate 22.04, 23.10, 24.04 and vanilla Ubuntu 24.04 and the problem persists.
Firefox packages from Mozilla, Canonical PPA and Snap are all broken.

Here is the log of setting the lock to 1 minute, starting playback, waiting till screensaver actiavtes, cancel the the screensaver and stop playback:

MOZ_LOG="LinuxWakeLock:5" firefox
libva info: VA-API version 1.19.0
libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_18
libva info: va_openDriver() returns 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::WakeLockTopic() created video-playing
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] InhibitFreeDesktopScreensaver()
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed(1)
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopScreensaver
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] InhibitFreeDesktopPower()
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.PowerManagement was not provided by any .service files
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitFailed(1)
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopPower
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00]   switched to WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal(): inhibited, objpath to unihibit: /org/freedesktop/portal/desktop/request/1_111/t
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 0 mShouldInhibit 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 object path: /org/freedesktop/portal/desktop/request/1_111/t
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::DBusUninhibitSucceeded() mShouldInhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::UninhibitFreeDesktopPortal() Inhibit removed

And this the log of simple start playback, stop playback

[Parent 7830: Main Thread]: D/LinuxWakeLock [7c333831aa30] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPortal
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 7830: Main Thread]: D/LinuxWakeLock [7c3313712b00] WakeLockTopic::InhibitFreeDesktopPortal(): inhibited, objpath to unihibit: /org/freedesktop/portal/desktop/request/1_111/t/1041562613

Forgot to add: Other browsers like Chrome, work as expected.

(In reply to Eugene San from comment #29)

Recently, with versions ~120 screensaver/lock inhibition stopped working completely.

It works for me on vanilla Ubuntu 23.10.

The video-playing inhibitor is only set when the video is visible (ie window is not minimized or fully covered by another window). Wayland is able to detect covered windows unlike X11 and was recently enabled in version 121. You can disable Wayland to see the difference:

 MOZ_ENABLE_WAYLAND=0 MOZ_LOG="LinuxWakeLock:5" firefox

I have the same issue on latest Gentoo, with Firefox 123.0

(In reply to Kestrel from comment #31)

(In reply to Eugene San from comment #29)

Recently, with versions ~120 screensaver/lock inhibition stopped working completely.

It works for me on vanilla Ubuntu 23.10.

The video-playing inhibitor is only set when the video is visible (ie window is not minimized or fully covered by another window). Wayland is able to detect covered windows unlike X11 and was recently enabled in version 121. You can disable Wayland to see the difference:

 MOZ_ENABLE_WAYLAND=0 MOZ_LOG="LinuxWakeLock:5" firefox

I have not tried Vanilla 23.10 and since other browsers do not have this issue I see no reason to blame/exclude any specific distro. Numerous reports support.
Now when I think about it, I tested both X and Wayland variants of Ubuntu so we can't blame X or Wayland either.
Maybe your routine/setup/hardware somehow avoids the issue and we should figure out how your setup is different from let's say generic install of "Vanilla" system in Virtualbox.

Also, why would you assume anyone taking their time to report the issue here, would test with the video in background or partially covered? It's a possibility, but common we are mostly gown-ups here.

Update.
Seems like the issue is not affecting KDE Plasma sessions.
I installed Plasma session on the same machine (Ubuntu Mate 23.10) and it works with the same Firefox instance without an issue.
Maybe "Media Playback" detection (indicated by the relevant Tray Icon) helps or maybe Plasma handling DBUS msgs differently.

I also tried freshly installed Kubuntu 24.04 and OpenSuSe Thumbleweed with plasma and they both work.

Here is the log:

MOZ_ENABLE_WAYLAND=0 MOZ_LOG="LinuxWakeLock:5" firefox
libva info: VA-API version 1.19.0
libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_18
libva info: va_openDriver() returns 0
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::WakeLockTopic() created video-playing
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650]   switched to WakeLockType FreeDesktopScreensaver
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca8721f670] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::InhibitScreensaver() Inhibited 0
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] InhibitFreeDesktopScreensaver()
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusInhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 6943 mShouldInhibit 1
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca8721f670] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::UninhibitScreensaver() Inhibited 1
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopScreensaver
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] UninhibitFreeDesktopScreensaver()
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusUninhibitScreensaver() mWaitingForDBusInhibit 0 mWaitingForDBusUninhibit 0 request id 6943
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 17406: Main Thread]: D/LinuxWakeLock [78ca7343e650] WakeLockTopic::DBusUninhibitSucceeded() mShouldInhibit 0
Flags: needinfo?(stransky)

This is still happening

Firefox 125.0.3 (64-bit)
XFCE xfwm4 4.18.0

dbus-send --dest=org.freedesktop.PowerManagement --print-reply=literal /org/freedesktop/PowerManagement/Inhibit org.freedesktop.PowerManagement.Inhibit.GetInhibitors

   array [
   ]

This returns nothing when firefox is opened for a while. If I restart firefox, then the inhibit is ok.

Sorry if this is irrelevant, but I have the same problem on Firefox 126.0 for Windows 10. Not expecting any replies, just wanted to mention it in case it's useful to anyone.

(In reply to Øystein Guneriussen from comment #36)

Sorry if this is irrelevant, but I have the same problem on Firefox 126.0 for Windows 10. Not expecting any replies, just wanted to mention it in case it's useful to anyone.

Please file another bug against Windows - it's different issue there.

This bug is never gonna get fixed right?

(In reply to Manu Barrio Linares [:Manu] from comment #38)

This bug is never gonna get fixed right?

Who knows. There's too many bugs and few developers who works on them. Feel free to join and try to solve it. There's a mini-howto:
https://mastransky.wordpress.com/2023/07/04/no-one-fights-alone-a-guide-to-your-first-firefox-patch-on-linux/

Manu, please run Firefox on terminal and attach a log with MOZ_LOG="LinuxWakeLock:5" env variable so we can check why Wake lock is not applied.
Run as:

MOZ_LOG="LinuxWakeLock:5" firefox > log.txt 2>&1

and attach the log here.
Thanks.

Flags: needinfo?(stransky) → needinfo?(mbarriolinares)
Attached file LinuxWakeLock.log —
(In reply to Martin Stránský [:stransky] (ni? me) from comment #40) > Manu, please run Firefox on terminal and attach a log with MOZ_LOG="LinuxWakeLock:5" env variable so we can check why Wake lock is not applied. > Run as: > ``` > MOZ_LOG="LinuxWakeLock:5" firefox > log.txt 2>&1 > ``` > and attach the log here. > Thanks.

Before closing firefox in the log I attached above, video was playing and there was NO inhibitor in dbus:

# dbus-send --dest=org.freedesktop.PowerManagement --print-reply=literal /org/freedesktop/PowerManagement/Inhibit org.freedesktop.PowerManagement.Inhibit.GetInhibitors
   array [
   ]
Flags: needinfo?(mbarriolinares)

It may be a dupe of Bug 1896235. Will try to look at it when Bug 1896235 lands.

Flags: needinfo?(stransky)

I suspect I am affected by this as well, after updating from FF 115 ESR to FF 128 ESR in F-40 with XFCE.

Can you test latest nightly please?
https://fedoraproject.org/wiki/How_to_debug_Firefox_problems#Testing_Mozilla_Nightly_binaries
Thanks.

Flags: needinfo?(stransky)

(In reply to Martin Stránský [:stransky] (ni? me) from comment #45)

Can you test latest nightly please?
https://fedoraproject.org/wiki/How_to_debug_Firefox_problems#Testing_Mozilla_Nightly_binaries
Thanks.

Been testing Nightly for the last 2 days, and the problem seems to be gone.
I'll continue to test for a few more days.

1 day later, happened again. Three big is still present in nightly.

When it happens in latest Nightly, try opening the video in a new window and see if playing creates a new inhibitor (as per Comment 42).

Please attach fresh MOZ_LOG="LinuxWakeLock:5" log from latest nightly.
Thanks.

Flags: needinfo?(mbarriolinares)

I'm not sure if I'm having the same issue but Firefox doesn't prevent screensaver from activating on my system. I can reproduce this on both ESR and the latest Nightly.

[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::WakeLockTopic() created video-playing
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType Initial
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0]   switched to WakeLockType FreeDesktopScreensaver
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5cfbcafa00] WakeLockListener topic video-playing state locked-foreground request lock 1
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::InhibitScreensaver() state uninhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): recent state uninhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): next state inhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopScreensaver
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] InhibitFreeDesktopScreensaver()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitFailed() Inhibit call failed : GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitFailed(1)
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::SwitchToNextWakeLockType() WakeLockType FreeDesktopScreensaver
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0]   switched to WakeLockType FreeDesktopPower
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::SendInhibit() WakeLockType FreeDesktopPower
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] InhibitFreeDesktopPower()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 16
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): recent state inhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): empty queue
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5cfbcafa00] WakeLockListener topic video-playing state unlocked request lock 0
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::UnInhibitScreensaver() state inhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): recent state inhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): next state uninhibited
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::SendUninhibit() WakeLockType FreeDesktopPower
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] UninhibitFreeDesktopPower()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitScreensaver() request id 16
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitFailed() UnInhibit call failed : GDBus.Error:org.xfce.PowerManager.Error.CookieNotFound: Неверные данные 
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitFailed()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::Shutdown() state inhibited
Summary: D-Bus wake lock mechanism malfunctions if Firefox is open for an extended period of time → [Linux] D-Bus wake lock mechanism malfunctions if Firefox is open for an extended period of time
Flags: needinfo?(stransky)

(In reply to Elijah from comment #50)

I'm not sure if I'm having the same issue but Firefox doesn't prevent screensaver from activating on my system. I can reproduce this on both ESR and the latest Nightly.

This looks like a problem with your system setup or so. From the log:

[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver()
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitScreensaver() proxy created
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusInhibitSucceeded(), mInhibitRequestID 16
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::ProcessNextRequest(): recent state inhibited

[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitScreensaver() request id 16
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitScreensaver() proxy created
[Parent 13156: Main Thread]: D/LinuxWakeLock [7f5ce86424c0] WakeLockTopic::DBusUninhibitFailed() UnInhibit call failed : GDBus.Error:org.xfce.PowerManager.Error.CookieNotFound: Неверные данн

So we got inhibit ID 16 and used it for uninhibit but it failed. Doesn't look like a Firefox bug.

Flags: needinfo?(stransky)

Redirect a needinfo that is pending on an inactive user to the triage owner.
:stransky, since the bug doesn't have a severity set, could you please set the severity or close the bug?

For more information, please visit BugBot documentation.

Flags: needinfo?(mbarriolinares) → needinfo?(stransky)

This is still happening on y system. Firefox seems to give up after a while. and it doesn't send any inhibitor requests to dbus.

I don't know why firefox gives up, restarting firefox makes it remember it NEEDS to send the inhibit requests to dbus.

System: Archlinux XFCE
firefox 140.0.2-1
xfwm4 4.20.0-2
xorg-server 21.1.18-2
linux 6.15.5.arch1-1
nvidia-dkms 575.64.03-1

Could you do new log with MOZ_LOG="LinuxWakeLock:5" again? Since we have some changes, a new log would be helpful.

Flags: needinfo?(mbarriolinares)
Severity: -- → S3
(In reply to Thinker Li [:sinker] from comment #54) > Could you do new log with MOZ_LOG="LinuxWakeLock:5" again? Since we have some changes, a new log would be helpful.
Here is the first part of the log when the dbus inhibitor was working.

Do you find the any line likes WakeLockTopic::DBusUninhibitFailed() or WakeLockTopic::DBusInhibitFailed(...) in the log?
I suspect PowerManager over DBus may fail several times for uninhibiting (>= 5). And, Firefox disables wake lock from this point at all.
We should retry here instead of just disabling it. Please check the log.

Here we have two cases, failures for inhibit and failures for uninhibit. For inhibit, it will try next wakelock type unitl all wakelock types has been tried, then it will disable wakelock from this point. One of issue is when we had one of types available at beginning and fails at one point later, it will try next type. That means once one and only one available wakelock type on a machine fail even just one time, wakelock will be disabled totally. We should stick at the same type forever once it success for once. And, keep retrying it.

For the uninhibit case, it tolerates 5 failures and disables wakelock after that. We should not have this threshold.

For the uninhibit case, it tolerates 5 failures and disables wakelock after that. We should not have this threshold.

Not disagreeing with this assessment, but was there any clue in the version control history about why that threshold was introduced? Would be unfortunate to accidentally reintroduce some other issue in the process of fixing this one.

Stransky, since you introduced this threshold mUninhibitAttempts, could you explain it?

(In reply to Thinker Li [:sinker] from comment #59)

Stransky, since you introduced this threshold mUninhibitAttempts, could you explain it?

It's here to don't try repeatedly talk to broken DBus service. We can adjust it or remove it but I'm not sure it will fix the issue here.

We may as well to discard broken uninhibit reply to expect the DBus wake lock service was restarted so the token we have is obviously obsoleted.

I don't see anybody interested in actually fixing this.

I'll try to add a g_timeout_add_seconds timer of 60 seconds when mUninhibitAttempts reach zero. After the timer, I will reset mUninhibitAttempts and try again. Also I'll remove the sWakeLockType = Unsupported logic, I see no benefit in not just "trying again after n seconds".

I have a fairly good CPU (Amd Ryzen 7 8700G + 32GB RAM) for build and testing, still this is my second time hacking the firefox source code. I'll appreciate any help

So my plan is:

  1. Removing "Unsupported" state.
  2. Introducing a "cooldown timer" when uninhibiting fails multiple times and add a retry logic.
  3. I'll try to scope it specifically for video playback, or generally by topic.

After many hours debugging, finally, a fix.

--- a/widget/gtk/WakeLockListener.cpp
+++ a/widget/gtk/WakeLockListener.cpp
@@ -380,11 +380,14 @@
                     },
                     [s = RefPtr{this}, this,
                      aMethod](GUniquePtr<GError>&& aError) {
+                      // We may get a broken reply if the peer DBus service was
+                      // restarted. In such case the service is not inhibited
+                      // anymore so consider this as success.
                       WAKE_LOCK_LOG(
                           "WakeLockTopic::DBusUninhibitFailed() %s call failed "
                           ": %s\n",
                           aMethod, aError->message);
-                      DBusUninhibitFailed();
+                      DBusUninhibitSucceeded();
                     });
           },
           [self = RefPtr{this}, this](GUniquePtr<GError>&& aError) {
@@ -527,7 +530,10 @@
                           "removed\n");
                     },
                     [s = RefPtr{this}, this](GUniquePtr<GError>&& aError) {
-                      DBusUninhibitFailed();
+                      // We may get a broken reply if the peer DBus service was
+                      // restarted. In such case the service is not inhibited
+                      // anymore so consider this as success.
+                      DBusUninhibitSucceeded();
                       WAKE_LOCK_LOG(
                           "WakeLockTopic::UninhibitFreeDesktopPortal() "
                           "Removing inhibit failed: %s\n",

So Firefox attempts to uninhibit, the DBus call fails due to the invalid token, and the WakeLockTopic class incorrectly remains in the Inhibited state, preventing further inhibition attempts.
My patch addresses this by modifying the error handling in DBusUninhibitScreensaver and UninhibitFreeDesktopPortal. Instead of calling DBusUninhibitFailed() when a D-Bus error occurs, it calls DBusUninhibitSucceeded(). This is good because a failed uninhibit call due to a restarted DBus service means the screensaver is already uninhibited (as the service restart clears all inhibitions). By treating the failure as a success, the WakeLockTopic state correctly transitions to Uninhibited, allowing future inhibition requests to proceed. And voila, I burned all my neurons and my cpu is on fire after many rebuilds of Firefox.

Flags: needinfo?(mbarriolinares)

Cool. Can you please submit it as phabricator patch? (if not, don't worry, just ping me and I can do it).

Flags: needinfo?(mbarriolinares)

There's a mini-howto for the patch submitting: https://mastransky.wordpress.com/2023/07/04/no-one-fights-alone-a-guide-to-your-first-firefox-patch-on-linux/

Thanks, will look at it ASAP.

Flags: needinfo?(mbarriolinares)
status-firefox143: --- → affected
status-firefox144: --- → affected
Flags: needinfo?(stransky)

https://hg.mozilla.org/mozilla-central/rev/e8dfb2bfed59

Status: REOPENED → RESOLVED
Closed: 1 year ago → 2 months ago
status-firefox144: affected → fixed
Resolution: --- → FIXED

The patch landed in nightly and beta is affected.
:stransky, is this bug important enough to require an uplift?

For more information, please visit BugBot documentation.

Flags: needinfo?(stransky)
status-firefox143: affected → wontfix
Flags: needinfo?(stransky)

for the record, in my limited testing it looks good so far, thanks

QA Whiteboard: [qa-triage-done-c145/b144]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: