2 Idle events per song change

[roizcorp]

Bug report

Describe the bug

I'm not sure if this even a bug, when using mpc idleloop per song change (song ends and new one starts) the command generates 2 player events while i believe in the past it generated only one

Also I think it would be useful to output also the action rather than only player e.g. next stop etc.

This happens with mpc 0.34 and mpd 23.9

Thank you

[unknown321]

It looks like idle events are not evicted fast enough after being received by client. Second idle command comes immidiately after response to first one, but event is still in queue, so you get it again.

Example sends idle as soon as it receives answer from previous command. Increase ReadDeadLine value or add time.Sleep in idle loop to get rid of duplicate events.

https://go.dev/play/p/C5U8wjiU7Ks

{"time":"2023-11-15T20:52:33.370192762+03:00","level":"INFO","msg":"Connected","addr":"localhost:6600","response":"OK MPD 0.23.5 "}
{"time":"2023-11-15T20:52:33.370252746+03:00","level":"INFO","msg":"Sending","command":"idle player\n"}
{"time":"2023-11-15T20:52:33.371701948+03:00","level":"INFO","msg":"Connected","addr":"localhost:6600","response":"OK MPD 0.23.5 "}
{"time":"2023-11-15T20:52:34.371775007+03:00","level":"INFO","msg":"Sending command: next"}
{"time":"2023-11-15T20:52:34.438501906+03:00","level":"INFO","msg":"Idle response: changed: player OK "}
{"time":"2023-11-15T20:52:34.438522919+03:00","level":"INFO","msg":"Sending","command":"idle player\n"}
{"time":"2023-11-15T20:52:34.439681475+03:00","level":"INFO","msg":"Idle response: changed: player OK "}
{"time":"2023-11-15T20:52:34.439696731+03:00","level":"INFO","msg":"Sending","command":"idle player\n"}
{"time":"2023-11-15T20:52:34.443113634+03:00","level":"INFO","msg":"Idle response: changed: player OK "}
{"time":"2023-11-15T20:52:34.443132941+03:00","level":"INFO","msg":"Sending","command":"idle player\n"}

[unknown321]

Disregard previous message, adding delays doesn't change anything.

mpd verbose log:

Nov 15 21:31:57 localhost mpd[143365]: client: [80] opened from 127.0.0.1:55972
Nov 15 21:31:57 localhost mpd[143365]: client: [81] opened from 127.0.0.1:55978
Nov 15 21:31:57 localhost mpd[143365]: client: [80] process command "idle player"
Nov 15 21:31:57 localhost mpd[143365]: client: [80] command returned 1
Nov 15 21:31:59 localhost mpd[143365]: client: [81] process command "next"
Nov 15 21:31:59 localhost mpd[143365]: playlist: play 51:"song.mp3"
Nov 15 21:31:59 localhost mpd[143365]: client: [81] command returned 0
Nov 15 21:31:59 localhost mpd[143365]: playlist: queue song 52:"next_song.mp3"
Nov 15 21:31:59 localhost mpd[143365]: client: [80] process command "idle player"
Nov 15 21:31:59 localhost mpd[143365]: client: [80] command returned 1
Nov 15 21:31:59 localhost mpd[143365]: client: [80] process command "idle player"
Nov 15 21:31:59 localhost mpd[143365]: client: [80] command returned 1
Nov 15 21:32:01 localhost mpd[143365]: client: [81] closed
Nov 15 21:32:01 localhost mpd[143365]: client: [80] closed

[unknown321]

alip/mpdcron#27 (comment)

Second event is being sent from LockUpdateSongTag function and only if song file is not local (nfs, http, etc.). (thanks me)

My files are not local (nfs), so I get two events. Patched LockUpdateSongTag, got only one event.

@roizcorp I assume you have same configuration?