Update module after input events

[rassie]

Feature Request

With default update time of a couple of seconds, modules like Spotify become slightly off-putting since clicking on its buttons doesn't produce an immediate response. From what I've seen in code, there is no automatical update after user input, which I'd consider more than appropriate in this case. Any chance this could be added? Thanks.

[tobi-wan-kenobi]

Oh, that sounds like a bug!

In bumblebee-status line 73ish, a redraw is initiated after an input event is detected. I tested it for pulseaudio, and there, it seems to work.

Have you observed the issue with other modules than spotify, as well?

[rassie]

Spotify is my only "interactive" module, so no, sorry.

[tobi-wan-kenobi]

Got it, will investigate what is going wrong. Thanks for the report!

[rassie]

I've checked again, I'm using pasink and layout modules, these react properly to mouse events, i.e. update themselves immediately. spotify does not.

[tobi-wan-kenobi]

Looking at the code, it seems the spotify has a very unusual way of assembling modules, and that might explain what you are seeing.

Unfortunately, I have no easy way of verifying whether the module works (not a spotify user myself). Would you be willing to do some tests for me with an experimental version?

[rassie]

Yeah, would be happy to. Cannot guarantee real-time response times though, but I'm on git version anyway, so it's basically no effort at all.

[tobi-wan-kenobi]

Perfect, thanks! And same for me reg. non-rraltime responses :-)

[tobi-wan-kenobi]

@rassie I implemented an experimental fix in main, was unable to test it, though. If you could provide any feedback, that would be much appreciated!

I decided to put it into main directly, so that other spotify users can complain as well, in case I broke something :)

[rassie]

@tobi-wan-kenobi Thanks for that! But this time, it's bad news: updating is still delayed and, on top of that, displaying current playing title broke, i.e. is not visible. Couldn't debug yet, maybe later today.

[tobi-wan-kenobi]

@rassie the problem with the title not being shown should be fixed now. Why the delay is still there, I need to further investigate.

Thanks for testing!

[rassie]

Can confirm the titles being back. Thanks!

[tobi-wan-kenobi]

What I find weird is that, as far as I can see, the spotify module should update every second. Let me try something, though. I will make the module update in the background, maybe the calls to dbus are sometimes laggy. Please let me know whether you see any improvement.

[rassie]

Let's make sure I'm not doing something funny with my start-up script. I'm using the following snippet, interval=5 has been changed from "normal" interval=2.5 to test your patches.

python3 ./bumblebee-status/bumblebee-status -m \
    title \
    spotify \
    nic \
    vpn \
    bluetooth \
    disk:root \
    load \
    cpu \
    sensors \
    nvidiagpu \
    memory \
    battery \
    pasink \
    layout \
    datetime \
    -a \
    load \
    cpu \
    sensors \
    battery \
    -p interval=5 nic.format="{ssid} {ip}" nic.states="^down" nvidiagpu.format="{temp}°C" traffic.showname=False memory.format="{percent:05.02f}%" disk.format="{path} {percent:05.02f}%" time.format="%H:%M" date.format="%a, %b %d %Y" home.path=/home

I don't see an obvious error in this configuration, but who knows.

Either way, your latest patch sadly does not provide any remedy. I've watched carefully for e.g. icon change from "pause" to "play" and those happen at the same time as my clock updates, i.e. after the global interval. Interestingly enough, sometimes spotify skips an update, i.e. needs more like 1.5 intervals to properly update. This might indeed have something to do with dbus being slow or something, even though I don't see any obvious problem.

As far as experiments go, I've added playerctl module, to see if it fares any better. I've tested it with both Spotify and QuodLibet and in both cases it's even slower than the spotify module (spotify = 1-1.5 cycles, playerctl = 1.5-2.5 cycles). So the good news is, you might want to test with playerctl if you don't have Spotify available.

[tobi-wan-kenobi]

playerctl uses a protocol that depends on dbus as well, which males it that much more likely that dbus is somehow involved in what is going on here.

Unfortunately, my main driver (void) doesn't seem to have dbus enabled by default, and I spectaculary failed to set it up properly so far, but I am working on it.

[tobi-wan-kenobi]

Did somenmodifications on the hope that they improve your situation. All of them address possible race conditions/concurrency concerns.

If you could try them out and give me an update, that would be much appreciated!

[rassie]

First off: somehow, the titles are broken again, probably in aa6238a5c6f5781ebd136810e115ba297ee15a23.

Now to the actual problem at hand: there are still no immediate updates on click. I've snooped at dbus-monitor for clues. One thing is certain: dbus is fast. Every click immediately sends a message and Spotify also reacts immediately. I also see all the messages that are supposed to be sent (I think). From the looks of it, all the information is there, but somehow no update is happening.

[tobi-wan-kenobi]

@rassie Sorry about the bug that slipped in again! I reverted to commit for now.

Funnily enough, with playerctl, I cannot reproduce the problem. When I click on the "play/pause" button in the bumblebee-status bar, it immediately updates the play state :thinking:

When you enable the debug log, do you see any error messages at all? Like failed command executions or something like that?

[rassie]

I can confirm that playertctl sometimes reacts immediately to the play/pause, but this doesn't happen every time for me, more like 50/50 (of course, not dependent on refresh interval). Experimenting with the "next" button, it seems it is capable of updating song titles immediately too, but somehow this works best when skipping multiple songs one after another, but instead of the current title, it switches to the previous one. Either way, it's not really consistent. Basically, all buttons work best when clicked roughly every second.

I'm afraid, I'm noit sure how to enable debug logging correctly -- I've followed bullet point 7 from https://i3wm.org/docs/debugging.html, but I don't get any output from that at all, which seemed a bit weird. With i3bar --verbose there is a lot of output, but nothing really button-related or any error.

[tobi-wan-kenobi]

That does sound like a concurrency issue, but I have no clue where that could come from...

Reg debugging: Sorry for being unclear, I meant the bumblebee-status debugging (-d to enable and -f to specify the logfile destination)

Thanks a lot for your patience!

[rassie]

Just tested: spotify module has exactly the same behaviour as playerctl: when skipping multiple tracks it shows previous instead of the current title, but updates immediately. Also clicking on play/pause half a second apart makes widgets update immediately.

[rassie]

OK, started up debugging with only the spotify module enabled. However, I only get input events, but no requests happening on the interval:

[2020-09-15 21:41:22,137] bumblebee-status INFO     input event: {"name":"spotify","instance":"spotify::3","button":1,"modifiers":[],"x":3637,"y":17,"relative_x":18,"relative_y":17,"width":26,"height":29}
[2020-09-15 21:41:22,138] cli              DEBUG    dbus-send --session --type=method_call --dest=org.mpris.MediaPlayer2.spotify                 /org/mpris/MediaPlayer2 org.mpris.MediaPlayer2.Player.Next
[2020-09-15 21:41:25,057] bumblebee-status INFO     input event: {"name":"spotify","instance":"spotify::3","button":1,"modifiers":[],"x":3638,"y":17,"relative_x":19,"relative_y":17,"width":26,"height":29}
[2020-09-15 21:41:25,058] cli              DEBUG    dbus-send --session --type=method_call --dest=org.mpris.MediaPlayer2.spotify                 /org/mpris/MediaPlayer2 org.mpris.MediaPlayer2.Player.Next

[rassie]

It's a bit more obvious with playerctl: it's apparently sending off playerctl next and then immediately queries playerctl status. I can simulate wrong behaviour by running playerctl next && playerctl metadata xesam:title. With a small timeout, everything works fine: playerctl next && sleep 0.2 && playerctl metadata xesam:title. Basically, dbus is really fast :)

No idea what to do about this apart from setting a small delay between an action and status request. Ideally, there would be a kind of feedback from MPRIS (apparently there is org.freedesktop.DBus.Properties.PropertiesChanged, provided players send that notification, of course), but a delay would be a quick and probably good enough solution.

[rassie]

~A quick note: Spotify does not support org.freedesktop.DBus.Properties.PropertiesChanged anyway :)~ EDIT: I'm wrong, please ignore...

[tobi-wan-kenobi]

Thanks for this great analysis! Will add the delay, probably generically, so that all. interactive dbus modules work reliably.

[tobi-wan-kenobi]

@rassie Thanks to your analysis, I was able to reproduce the issue! (Basically, faking my own playerctl that adds an artifical delay before updating the status).

I hope this is now fixed in main by adding a 0.2s delay before updating (in my tests, that delay was barely noticable). Also, the delay is configurable via the parameter "engine.input_delay".

[rassie]

@tobi-wan-kenobi Thanks! My testing has been limited, but I can confirm that playerctl seems to work as expected now. However, somehow spotify could care less about the change even with longer delay, I'll try to figure out what's happening there.

[tobi-wan-kenobi]

Hello @rassie !

Unfortunately, I have not made progress on that issue. I saw, however, that there was a PR for spotify today. I am pretty sure this won't fix the issue, but in case you want to re-test.

[tobi-wan-kenobi]

Closing for now, as this is a specific module error, I cannot reproduce it, and all other modules should update correctly on user input.

If the problem persists, please reopen.