[MPD] Fixed loosing pending commands on broken idle connection

[christianwicke]

I'm using MPD on an old tablet. I wrote a rule to play music to alert when windows are open to long. It works in general.

Unfortunately, when MPD is idle for a long time, the connection get lost. Then (when my window rule send the play command) the mpd binding automatically reconnects after 60s, but the pending commands are lost. Therefore my alert is not working most of the time.

Expected Behavior

The mpd binding should handle reconnect on idle connections without loosing commands. (This is similar to JDBC connection pools like HikariCP handle broken idle JDBC connections.)

Current Behavior

The mpd binding looses pending commands when reconnecting after detecting a broken connection.

Here is a trace log of such a case (formatted with extra empty lines):

...
2024-01-14 11:19:20.249 [TRACE] [nternal.protocol.MPDConnectionThread] - received line 'OK'
2024-01-14 11:19:20.249 [TRACE] [nternal.protocol.MPDConnectionThread] - send command 'idle'
2024-01-14 11:19:20.249 [TRACE] [nternal.protocol.MPDConnectionThread] - read response for command 'idle'

2024-01-14 15:09:11.367 [DEBUG] [nding.mpd.internal.action.MPDActions] - sendCommand called with clear
2024-01-14 15:09:11.368 [DEBUG] [nternal.protocol.MPDConnectionThread] - insert command 'clear' at position -1
2024-01-14 15:09:11.368 [TRACE] [nternal.protocol.MPDConnectionThread] - send command 'noidle'
2024-01-14 15:09:11.369 [DEBUG] [nding.mpd.internal.action.MPDActions] - sendCommand called with load
2024-01-14 15:09:11.369 [DEBUG] [nternal.protocol.MPDConnectionThread] - insert command 'load' at position -1
2024-01-14 15:09:11.371 [DEBUG] [nding.mpd.internal.action.MPDActions] - sendCommand called with play
2024-01-14 15:09:11.372 [DEBUG] [nternal.protocol.MPDConnectionThread] - insert command 'play' at position -1

2024-01-14 15:09:12.215 [TRACE] [nternal.protocol.MPDConnectionThread] - received line 'null'

2024-01-14 15:09:12.216 [DEBUG] [nternal.protocol.MPDConnectionThread] - Closing socket
2024-01-14 15:10:12.216 [DEBUG] [nternal.protocol.MPDConnectionThread] - opening connection to 192.168.178.43 port 6620

2024-01-14 15:10:12.217 [TRACE] [nternal.protocol.MPDConnectionThread] - read response for command 'connect'
2024-01-14 15:10:12.834 [TRACE] [nternal.protocol.MPDConnectionThread] - received line 'OK MPD 0.23.5'

2024-01-14 15:10:12.834 [TRACE] [nternal.protocol.MPDConnectionThread] - send command 'status'
2024-01-14 15:10:12.835 [TRACE] [nternal.protocol.MPDConnectionThread] - read response for command 'status'
2024-01-14 15:10:12.840 [TRACE] [nternal.protocol.MPDConnectionThread] - received line 'volume: 55'
2024-01-14 15:10:12.840 [TRACE] [nternal.protocol.MPDConnectionThread] - received line 'repeat: 0'
...

The received line 'null' shows the broken connection.

I looked into the code and can explain the behavior:

1. On receiving a null line, an IOException is raised MPDConnectionThread:287
2. This exception is caught in the main run method MPDConnectionThread:85
3. The while loop in that run method starts the next iteration an clears the pending commands MPDConnectionThread:73

Is this on purpose, especially for broken idle connections?

Possible Solution

I think broken idle connections should be handled by a reconnect right after instead of sleeping for 60s and clearing the pending commands.
This pull request does this. It introduces a new variable wakingUpFromIdle which keeps track of whether the last command sent was a "noidle" which tries to wakeup the idle mode. If the connection reset occurs right after that, the connection is rebuilt right away.

Steps to Reproduce (for Bugs)

I can reproduce the bug with my android tablet, if I wait long enough, but I cannot reproduce the error otherwise. If I just kill the MPD instance, the connection ist terminated properly and the MPD binding detects the closed connection. It probalby is possible using a firewall in between which silently terminates the connection, but I didn't try this.

Context

See first paragraph

Your Environment

I'm using openhab 4.1.0 as a docker container openhab/openhab:4.1.0. on debian bookworm. Besides the 4.1.0 binding I also used the own built MPD binding from the trunk.

[stefanroellin]

Thanks for your changes. It makes sense to try to reconnect in the described situation.

My reasoning for clearing the pending commands was that in my opinion it does not make sense, to send the pending commands, if the connection was lost for a long time - let's say for one hour.

[lsiepel]

LGTM

[christianwicke]

Thank you very much for merging my changes!