Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix(music): mpris - handle no active mpris player on launch & hide label when player list is empty. #481

Merged
merged 1 commit into from
Mar 18, 2024

Conversation

slowsage
Copy link
Contributor

@slowsage slowsage commented Mar 4, 2024

Sometimes, I see the NoActivePlayer DBusError when no music players are running.

2024-03-03T21:41:53.536515Z ERROR ironbar::logging: 48: The application panicked (crashed).
Message:  Failed to connect to D-Bus: DBusError(TransportError(D-Bus error: No player is being controlled by playerctld (com.github.altdesktop.playerctld.NoActivePlayer)))
Location: src/clients/music/mpris.rs:40

The first commit prevents the panic so the song shows when the player is started after ironbar was launched.

The second commit checks if all the players have been cleared out and sends None to hide the label in this case. With this change, the music label does not stay after the app is closed.

I tested by
1.start ironbar
2. then spotify,
3. then another player
4. and closed both
5. and restarted spotify.

The show/hide behavior is as expected: 1. none, 2. song1, 3. song2, 4. song2->song1->None, 5. song1

It's entirely possible I missed the actual mechanism to hide the label when no players active. Please let me know if there is a better way. Thank you!

@slowsage slowsage changed the title Fix/mpris Fix(music): mpris - handle no active mpris player on launch & hide label when player list is empty. Mar 4, 2024
Copy link
Owner

@JakeStanger JakeStanger left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for this, looks like a good fix again. Just one small code quality change if you can please.

@JakeStanger
Copy link
Owner

JakeStanger commented Mar 4, 2024

It's entirely possible I missed the actual mechanism to hide the label when no players active

I'll double check this later, but it's very possible it's not implemented

EDIT: Ignore the closure, fat fingered the wrong button.

@JakeStanger JakeStanger closed this Mar 4, 2024
@JakeStanger JakeStanger reopened this Mar 4, 2024
@slowsage
Copy link
Contributor Author

slowsage commented Mar 4, 2024

Change made. Thank you!

@slowsage
Copy link
Contributor Author

slowsage commented Mar 4, 2024

Please hold off on committing it. There might be an issue. Want to test for a few days more. Thank you. I will comment here once confirmed.

@slowsage
Copy link
Contributor Author

slowsage commented Mar 5, 2024

Ready for review. Added more checks as I found them.

Possible issue: I removed the status playing check on new player added since it complicated the code. It seems to work fine without it since the active player gets set on the playing/progress event. But this might be a function of my app. Can add it back if you prefer.

Apart from the above issue, it seems to handle all edge cases on my setup with at most a second of delay after a player is terminated.

Please take a look and possibly even run this for a few days/weeks if you have time. Do not want to rush this since user environments vary and concurrency is involved.

Thank you!!!

Copy link
Owner

@JakeStanger JakeStanger left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Only 1 tiny nit if you get a chance, but otherwise lgtm. Thanks for your work on this!

I'll give this a few tests myself over the weekend, and if all looks good I'll merge. If anybody following master does find any bugs we can get it sorted before next release.

@slowsage
Copy link
Contributor Author

slowsage commented Mar 7, 2024

Apologies. Just ran into one more edge case.

I can get back after a month of testing. If you want to close this till then, please do so.

@JakeStanger
Copy link
Owner

No rush, take your time. You can convert this to a draft if you want, but either way just give me a ping when you're happy with it.

@slowsage slowsage marked this pull request as draft March 8, 2024 13:27
@slowsage slowsage marked this pull request as ready for review March 10, 2024 21:41
@slowsage
Copy link
Contributor Author

This is fairly stable (crossing fingers). Biggest new addition: made the lock acquisition order consistent with your earlier shutdown of player (current_player, then players). Please take a look at the locking code changes.
The only possible downgrade in behavior I can think of is the following sequence:

  • player1.play() [shows player1]
  • player2.play() [shows player2]
  • player2.pause() [shows player2 while player 1 is playing].

It switches to player1 if you either

  1. pause and play player1
  2. close player2.

Either way, I think its minor and can be a separate pull request once this is stable and merged in.

@JakeStanger
Copy link
Owner

Changes LGTM, thanks. Agreed that 'downgrade' is very minor, so happy to let that slide for now.

I'll give this a test over the next couple of days myself then merge.

@JakeStanger
Copy link
Owner

JakeStanger commented Mar 17, 2024

I have just given this a test through, and I've found a regression: there's a second delay between player some updates (such as play/pause) and Ironbar reflecting that, even if toggled through the Ironbar popup.

There is also a pre-existing bug I've found where if you close a player it remains the 'active' one, then trying to play it throws an error. I'm not sure how easy this is to fix, but it might be worth including a fix here as it's in scope. If not, I'll log a separate bug for it.

@slowsage
Copy link
Contributor Author

slowsage commented Mar 17, 2024

I have just given this a test through, and I've found a regression: there's a second delay between player some updates (such as play/pause) and Ironbar reflecting that, even if toggled through the Ironbar popup.

Verified. Missed this regression. Thank you for noticing this. Will figure out why and get back.. Update: Should be fixed. Enclosed the lock! and loop in a block before the sleep call in the latest commit.

There is also a pre-existing bug I've found where if you close a player it remains the 'active' one, then trying to play it throws an error. I'm not sure how easy this is to fix, but it might be worth including a fix here as it's in scope. If not, I'll log a separate bug for it.

I cannot reproduce this. Which player? My guess is yet another error is being thrown in the Err(err) => error!("{err:?}"), match in listen_player_events that should be caught and handle_shutdown should be called in that case as well. Do you have a log of any errors?

@JakeStanger
Copy link
Owner

JakeStanger commented Mar 17, 2024

I cannot reproduce this. Which player?

I tested with Ryhthmbox:

  1. Play video on YouTube via Firefox
  2. Pause video
  3. Open Rhythmbox
  4. Start playing a song from Rhythmbox
  5. Pause Rhythmbox
  6. Close Rhythmbox
  7. MPRIS widget continues to show Rhythmbox as player. Clicking play from widget causes error.
Log
2024-03-17T16:18:07.495797Z DEBUG ironbar: 288: Loaded config file
2024-03-17T16:18:07.495839Z  INFO ironbar: 111: Ironbar version 0.15.0-pre
2024-03-17T16:18:07.495846Z  INFO ironbar: 112: Starting application
2024-03-17T16:18:07.498194Z DEBUG sctk: 456: Bound new global [49] wl_output v4    
2024-03-17T16:18:07.498223Z DEBUG sctk: 456: Bound new global [50] wl_output v4    
2024-03-17T16:18:07.498239Z DEBUG sctk: 456: Bound new global [51] wl_output v4    
2024-03-17T16:18:07.498259Z DEBUG sctk: 496: Bound new global [48] zxdg_output_manager_v1 v3    
2024-03-17T16:18:07.498302Z DEBUG sctk: 456: Bound new global [14] wl_seat v7    
2024-03-17T16:18:07.498334Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel::manager: 25: Bound to ZwlForeignToplevelManagerV1 global
2024-03-17T16:18:07.498355Z DEBUG ironbar::clients::wayland::wlr_data_control::manager: 29: Bound to ZwlDataControlManagerV1 global
2024-03-17T16:18:07.498416Z DEBUG ironbar::clients::wayland: 318: received roundtrip request
2024-03-17T16:18:07.498710Z DEBUG ironbar::clients::wayland::wl_output: 64: Handler received new output
2024-03-17T16:18:07.498739Z DEBUG ironbar::clients::wayland::wl_output: 64: Handler received new output
2024-03-17T16:18:07.498752Z DEBUG ironbar::clients::wayland::wl_output: 64: Handler received new output
2024-03-17T16:18:07.498765Z DEBUG ironbar::clients::wayland::wl_seat: 30: Handler received new capability
2024-03-17T16:18:07.498771Z DEBUG ironbar::clients::wayland::wl_seat: 38: Adding new data control device
2024-03-17T16:18:07.498791Z DEBUG ironbar::clients::wayland::wl_seat: 30: Handler received new capability
2024-03-17T16:18:07.498802Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498808Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498814Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498820Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498825Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498831Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498837Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498842Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498848Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:07.498880Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.498908Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.498923Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.498962Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.498983Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.499001Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.499020Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.499063Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.499097Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:07.499272Z DEBUG ironbar::clients::wayland::wlr_data_control: 208: Handler received selection event
2024-03-17T16:18:07.499333Z DEBUG ironbar::clients::wayland::wlr_data_control: 240: Receiving mime type: text/plain;charset=utf-8
2024-03-17T16:18:07.550400Z  INFO ironbar::ipc::server: 37: Starting IPC on /run/user/1000/ironbar-ipc.sock
2024-03-17T16:18:07.550778Z DEBUG ironbar::style: 31: Loaded css from '/home/jake/.config/ironbar/style.css'
2024-03-17T16:18:07.551132Z DEBUG ironbar::style: 67: Installed CSS file watcher on '/home/jake/.config/ironbar/style.css'
2024-03-17T16:18:07.551166Z DEBUG ironbar: 190: Received activation signal, initialising bars
2024-03-17T16:18:07.552152Z  INFO ironbar::bar: 120: Initializing bar 'bar-11' on 'DP-1'
2024-03-17T16:18:07.563471Z DEBUG ironbar::clients::music::mpris: 267: Creating new subscription
2024-03-17T16:18:07.564547Z DEBUG ironbar::clients::music::mpris: 47: Adding MPRIS player 'Mozilla Firefox'
2024-03-17T16:18:07.564732Z DEBUG ironbar::clients::music::mpris: 58: Setting active player to 'Mozilla Firefox'
2024-03-17T16:18:07.564742Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Mozilla Firefox'
2024-03-17T16:18:07.564922Z DEBUG ironbar::popup: 117: Registered popup content for #12
2024-03-17T16:18:07.565623Z DEBUG ironbar::popup: 117: Registered popup content for #14
2024-03-17T16:18:07.565710Z DEBUG ironbar::bar: 294: Showing bar: bar-11
2024-03-17T16:18:07.584021Z  INFO ironbar::bar: 120: Initializing bar 'bar-16' on 'DP-2'
2024-03-17T16:18:07.594292Z DEBUG ironbar::clients::music::mpris: 267: Creating new subscription
2024-03-17T16:18:07.595318Z DEBUG ironbar::popup: 117: Registered popup content for #17
2024-03-17T16:18:07.595660Z DEBUG ironbar::popup: 117: Registered popup content for #19
2024-03-17T16:18:07.595760Z DEBUG ironbar::bar: 294: Showing bar: bar-16
2024-03-17T16:18:07.595859Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Mozilla Firefox'
2024-03-17T16:18:07.597830Z  INFO ironbar::bar: 120: Initializing bar 'bar-21' on 'DP-3'
2024-03-17T16:18:07.607649Z DEBUG ironbar::clients::music::mpris: 267: Creating new subscription
2024-03-17T16:18:07.608587Z DEBUG ironbar::popup: 117: Registered popup content for #22
2024-03-17T16:18:07.608938Z DEBUG ironbar::popup: 117: Registered popup content for #24
2024-03-17T16:18:07.609050Z DEBUG ironbar::bar: 294: Showing bar: bar-21
2024-03-17T16:18:07.609059Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Mozilla Firefox'
2024-03-17T16:18:07.611618Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.mozilla/firefox/firefox-mpris/1000_0.png --> Local("/home/jake/.mozilla/firefox/firefox-mpris/1000_0.png") (size: 128)
2024-03-17T16:18:07.614437Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.mozilla/firefox/firefox-mpris/1000_0.png --> Local("/home/jake/.mozilla/firefox/firefox-mpris/1000_0.png") (size: 128)
2024-03-17T16:18:07.616518Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.mozilla/firefox/firefox-mpris/1000_0.png --> Local("/home/jake/.mozilla/firefox/firefox-mpris/1000_0.png") (size: 128)
2024-03-17T16:18:07.618708Z DEBUG ironbar::modules: 327: Closing popup for music [#12]
2024-03-17T16:18:08.661068Z DEBUG ironbar::modules: 289: Toggling popup for music [#12]
2024-03-17T16:18:09.843716Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Mozilla Firefox'
2024-03-17T16:18:11.372890Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Mozilla Firefox'
2024-03-17T16:18:15.761634Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 47: Manager received new handle
2024-03-17T16:18:15.761724Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 53: Handler received new handle
2024-03-17T16:18:16.576578Z DEBUG ironbar::clients::music::mpris: 47: Adding MPRIS player 'Rhythmbox'
2024-03-17T16:18:20.487462Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Rhythmbox'
2024-03-17T16:18:20.488785Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.cache/rhythmbox/album-art/./00c --> Local("/home/jake/.cache/rhythmbox/album-art/./00c") (size: 128)
2024-03-17T16:18:20.492285Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.cache/rhythmbox/album-art/./00c --> Local("/home/jake/.cache/rhythmbox/album-art/./00c") (size: 128)
2024-03-17T16:18:20.495640Z DEBUG ironbar::image::provider: 48: Resolved file:///home/jake/.cache/rhythmbox/album-art/./00c --> Local("/home/jake/.cache/rhythmbox/album-art/./00c") (size: 128)
2024-03-17T16:18:22.193724Z DEBUG ironbar::clients::music::mpris: 151: Sending update using 'Rhythmbox'
2024-03-17T16:18:23.428916Z DEBUG ironbar::clients::wayland::wlr_foreign_toplevel: 97: Handler received handle close
2024-03-17T16:18:24.499170Z DEBUG ironbar::modules: 289: Toggling popup for music [#12]
2024-03-17T16:18:25.459179Z ERROR ironbar::clients::music::mpris: 222: Could not find player

@slowsage
Copy link
Contributor Author

I cannot reproduce the error now with the latest version of PR.

My earlier commit that released the lock before sleeping should have fixed the issue in your logs. This commit should have ensured that in step 7, MPRIS will show firefox again before you had a chance to interact with the stale Rhythmbox player. Going by the log's line 222 in mpris.rs, it was before the commit that released the locks:

2024-03-17T16:18:25.459179Z ERROR ironbar::clients::music::mpris: 222: Could not find player

Only thing I could think of: Could not reproduce your exact error but I set the delay in the loop to 5 seconds instead of 1 while holding on to the lock (on purpose) to stress test holding the lock.This triggered another error which we now handle by shutting down the player.

Another reason to shutdown the player could be when the command macro calls fail but feel its better to get this PR in first to isolate issues that may crop up. Feel free to assign me a new issue if it still happens with the new changes.

@JakeStanger
Copy link
Owner

I think you're right, I was a commit behind. Sorry about that! I have just tested again on the latest commit and everything seems solid.

The commits at the moment are possibly a bit technical and separated - do you think you could squash them down to reflect each bug please, as each commit will form an entry in the changelog? Once that's done I think it's merge time :)

@JakeStanger
Copy link
Owner

Cheers for all your work on this!

@JakeStanger JakeStanger merged commit 8254627 into JakeStanger:master Mar 18, 2024
8 checks passed
@slowsage slowsage deleted the fix/mpris branch March 20, 2024 13:09
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants