InvalidMessage when playing a song

Question

InvalidMessage when playing a song

Closed this issue a year ago · 7 comments

Hi, I was trying to use mpd-discord-rpc, which uses this library, and I'm getting this error when I play a song:

I opened an issue in that repo and the author told me the error seems to be coming from this library so I should post it here. I'm on macOS Monterey by the way. Let me know if you need any extra info.

Answer 1 · 2023-05-27T09:54:42.000Z

Hi, thanks for reporting.

Could you attempt to reproduce this with a build of mpd-discord-rpc that has debug logging enabled? ~~If you're comfortable compiling the software yourself, you can enable these messages by changing this line to something like tracing_subscriber::fmt().with_max_level(tracing::Level::TRACE).init();.~~

Answer 2 · 2023-05-27T10:15:57.000Z

Actually, you don't need to recompile anything, you can just run the binary you already have with the RUST_LOG environment variable set to trace (e.g. RUST_LOG=trace mpd-discord-rpc).

Answer 3 · 2023-05-27T13:51:30.000Z

Here it is:

RUST_LOG=trace mpd-discord-rpc
2023-05-27T13:44:07.825112Z DEBUG universal_config: Using config dir: /Users/david/Library/Application Support/discord-rpc
2023-05-27T13:44:07.825174Z DEBUG universal_config: Found file at: '/Users/david/Library/Application Support/discord-rpc/config.toml
2023-05-27T13:44:07.829147Z DEBUG discord_rpc_client::connection::manager: Starting sender loop
2023-05-27T13:44:07.829162Z DEBUG discord_rpc_client::connection::manager: Connecting
2023-05-27T13:44:07.829202Z DEBUG discord_rpc_client::connection::manager: Performing handshake
2023-05-27T13:44:07.829483Z TRACE mio::poll: registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
2023-05-27T13:44:07.829628Z DEBUG discord_rpc_client::connection::base: -> Message { opcode: Handshake, payload: "{\"client_id\":\"677226551607033903\",\"nonce\":\"cc2684db-a96a-4031-8324-4dfc9b50ce02\",\"v\":1}" }
2023-05-27T13:44:07.830050Z TRACE client connection:connect: mpd_protocol::connection: read=14
2023-05-27T13:44:07.830065Z  INFO client connection:connect: mpd_protocol::connection: connected successfully version="0.23.5"
2023-05-27T13:44:07.830424Z  INFO mpd_utils::persistent_client: Connected to 'localhost:6600'
2023-05-27T13:44:07.830440Z TRACE client connection:run loop: mpd_client::client::connection: sending initial idle command
2023-05-27T13:44:07.830479Z DEBUG client connection:run loop:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:44:07.830834Z TRACE client connection:run loop: mpd_client::client::connection: entering run loop
2023-05-27T13:44:07.832973Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command received command=CommandList([Command(b"status")])
2023-05-27T13:44:07.832998Z DEBUG client connection:run loop:iteration{state=Idling}:send{command=Command(b"noidle")}: mpd_protocol::connection: sent command length=7
2023-05-27T13:44:07.833090Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: read=3
2023-05-27T13:44:07.833103Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: finished response
2023-05-27T13:44:07.833110Z DEBUG client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: received complete response frames=1 fields=0 error=false
2023-05-27T13:44:07.833138Z DEBUG client connection:run loop:iteration{state=Idling}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:44:07.833152Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command sent successfully
2023-05-27T13:44:07.833224Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=130
2023-05-27T13:44:07.833244Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:44:07.833255Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:44:07.833262Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:44:07.833268Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:44:07.833274Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:44:07.833281Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:44:07.833395Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="2"
2023-05-27T13:44:07.833406Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="1"
2023-05-27T13:44:07.833412Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:44:07.833452Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="stop"
2023-05-27T13:44:07.833458Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:44:07.833462Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=10 error=false
2023-05-27T13:44:07.833528Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:44:07.833751Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"status")])
2023-05-27T13:44:07.833785Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:44:07.833866Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=130
2023-05-27T13:44:07.833877Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:44:07.833884Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:44:07.833890Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:44:07.834000Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:44:07.834015Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:44:07.834051Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:44:07.834182Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="2"
2023-05-27T13:44:07.834190Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="1"
2023-05-27T13:44:07.834196Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:44:07.834353Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="stop"
2023-05-27T13:44:07.834360Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:44:07.834365Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=10 error=false
2023-05-27T13:44:07.835934Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:44:07.937580Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: reached next command timeout, idling
2023-05-27T13:44:07.937629Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:44:08.331359Z DEBUG discord_rpc_client::connection::base: Received 366 bytes
2023-05-27T13:44:08.331384Z DEBUG discord_rpc_client::connection::base: <- Message { opcode: Frame, payload: "{\"cmd\":\"DISPATCH\",\"data\":{\"v\":1,\"config\":{\"cdn_host\":\"cdn.discordapp.com\",\"api_endpoint\":\"//discord.com/api\",\"environment\":\"production\"},\"user\":{\"id\":\"143647011101605888\",\"username\":\"Allavaz\",\"discriminator\":\"6597\",\"avatar\":\"c643e296cdb887f593a47ff28f536ebe\",\"avatar_decoration\":null,\"bot\":false,\"flags\":4194304,\"premium_type\":0}},\"evt\":\"READY\",\"nonce\":null}" }
2023-05-27T13:44:08.331399Z DEBUG discord_rpc_client::connection::manager: Handshake completed
2023-05-27T13:44:08.331403Z DEBUG discord_rpc_client::connection::manager: Connected
2023-05-27T13:44:08.331414Z DEBUG discord_rpc_client::connection::base: -> Message { opcode: Frame, payload: "{\"cmd\":\"SET_ACTIVITY\",\"args\":{\"pid\":14616},\"nonce\":\"72664c87-c125-4876-9894-69735c27db41\"}" }
2023-05-27T13:44:08.832083Z DEBUG discord_rpc_client::connection::base: Received 100 bytes
2023-05-27T13:44:08.832116Z DEBUG discord_rpc_client::connection::base: <- Message { opcode: Frame, payload: "{\"cmd\":\"SET_ACTIVITY\",\"data\":null,\"evt\":null,\"nonce\":\"72664c87-c125-4876-9894-69735c27db41\"}" }
2023-05-27T13:46:21.890005Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: read=21
2023-05-27T13:46:21.890038Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: parsed field key="changed" value="playlist"
2023-05-27T13:46:21.890055Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:21.890065Z DEBUG client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: received complete response frames=1 fields=1 error=false
2023-05-27T13:46:21.890083Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: handling idle response
2023-05-27T13:46:21.890092Z DEBUG client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: state change subsystem=Queue
2023-05-27T13:46:21.890207Z DEBUG client connection:run loop:iteration{state=Idling}:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:46:21.890261Z  INFO mpd_discord_rpc: Detected change, updating status
2023-05-27T13:46:21.890278Z DEBUG mpd_discord_rpc: Change: SubsystemChange(Queue)
2023-05-27T13:46:21.890324Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command received command=CommandList([Command(b"status")])
2023-05-27T13:46:21.890348Z DEBUG client connection:run loop:iteration{state=Idling}:send{command=Command(b"noidle")}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:21.890416Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: read=3
2023-05-27T13:46:21.890427Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:21.890433Z DEBUG client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: received complete response frames=1 fields=0 error=false
2023-05-27T13:46:21.890456Z DEBUG client connection:run loop:iteration{state=Idling}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:21.890465Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command sent successfully
2023-05-27T13:46:21.890574Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=130
2023-05-27T13:46:21.890588Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:46:21.891493Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:46:21.891509Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:46:21.891516Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:46:21.891644Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:46:21.891677Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:46:21.891690Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="3"
2023-05-27T13:46:21.891749Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="2"
2023-05-27T13:46:21.891765Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:46:21.891773Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="stop"
2023-05-27T13:46:21.891840Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:21.891847Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=10 error=false
2023-05-27T13:46:21.891855Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:21.892526Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"status")])
2023-05-27T13:46:21.892568Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:21.892656Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=130
2023-05-27T13:46:21.892699Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:46:21.892714Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:46:21.892725Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:46:21.892881Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:46:21.892898Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:46:21.892911Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:46:21.893056Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="3"
2023-05-27T13:46:21.893070Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="2"
2023-05-27T13:46:21.893082Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:46:21.893271Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="stop"
2023-05-27T13:46:21.893288Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:21.893298Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=10 error=false
2023-05-27T13:46:21.893312Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:21.996202Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: reached next command timeout, idling
2023-05-27T13:46:21.996278Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:46:22.153535Z DEBUG discord_rpc_client::connection::base: -> Message { opcode: Frame, payload: "{\"cmd\":\"SET_ACTIVITY\",\"args\":{\"pid\":14616},\"nonce\":\"f060f9f2-9f2c-4a04-b4b2-1e3c65e7a214\"}" }
2023-05-27T13:46:22.657938Z DEBUG discord_rpc_client::connection::base: Received 100 bytes
2023-05-27T13:46:22.657974Z DEBUG discord_rpc_client::connection::base: <- Message { opcode: Frame, payload: "{\"cmd\":\"SET_ACTIVITY\",\"data\":null,\"evt\":null,\"nonce\":\"f060f9f2-9f2c-4a04-b4b2-1e3c65e7a214\"}" }
2023-05-27T13:46:24.774820Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: read=19
2023-05-27T13:46:24.774848Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: parsed field key="changed" value="player"
2023-05-27T13:46:24.774867Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:24.774879Z DEBUG client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: received complete response frames=1 fields=1 error=false
2023-05-27T13:46:24.774898Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: handling idle response
2023-05-27T13:46:24.774907Z DEBUG client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: state change subsystem=Player
2023-05-27T13:46:24.775017Z DEBUG client connection:run loop:iteration{state=Idling}:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:46:24.775068Z  INFO mpd_discord_rpc: Detected change, updating status
2023-05-27T13:46:24.775073Z DEBUG mpd_discord_rpc: Change: SubsystemChange(Player)
2023-05-27T13:46:24.775116Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command received command=CommandList([Command(b"status")])
2023-05-27T13:46:24.775150Z DEBUG client connection:run loop:iteration{state=Idling}:send{command=Command(b"noidle")}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:25.487739Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: read=19
2023-05-27T13:46:25.487769Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: parsed field key="changed" value="player"
2023-05-27T13:46:25.487780Z TRACE client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:25.487786Z DEBUG client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: received complete response frames=1 fields=1 error=false
2023-05-27T13:46:25.487808Z DEBUG client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: state change subsystem=Player
2023-05-27T13:46:25.487843Z DEBUG client connection:run loop:iteration{state=Idling}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:25.487858Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: command sent successfully
2023-05-27T13:46:25.488089Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=238
2023-05-27T13:46:25.488106Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:46:25.488124Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:46:25.488244Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:46:25.488261Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:46:25.488273Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:46:25.488286Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:46:25.488371Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="3"
2023-05-27T13:46:25.488385Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="2"
2023-05-27T13:46:25.488431Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:46:25.488614Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="play"
2023-05-27T13:46:25.488629Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="song" value="1"
2023-05-27T13:46:25.488641Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="songid" value="2"
2023-05-27T13:46:25.488722Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="time" value="0:300"
2023-05-27T13:46:25.488741Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="elapsed" value="0.000"
2023-05-27T13:46:25.488754Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="bitrate" value="463"
2023-05-27T13:46:25.488767Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="duration" value="299.970"
2023-05-27T13:46:25.488928Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="audio" value="44100:16:2\0\u{8}\u{1}\0\0\0,\u{1}\0\0\0\0\0\0"
2023-05-27T13:46:25.488947Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:25.488957Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=17 error=false
2023-05-27T13:46:25.489114Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:25.489202Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"status")])
2023-05-27T13:46:25.489257Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:25.489404Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=238
2023-05-27T13:46:25.489418Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:46:25.489437Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:46:25.489637Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:46:25.489665Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:46:25.489681Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:46:25.489889Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:46:25.489906Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="3"
2023-05-27T13:46:25.489918Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="2"
2023-05-27T13:46:25.491040Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:46:25.491068Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="play"
2023-05-27T13:46:25.491081Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="song" value="1"
2023-05-27T13:46:25.491312Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="songid" value="2"
2023-05-27T13:46:25.491327Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="time" value="0:300"
2023-05-27T13:46:25.491339Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="elapsed" value="0.000"
2023-05-27T13:46:25.491649Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="bitrate" value="463"
2023-05-27T13:46:25.491665Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="duration" value="299.970"
2023-05-27T13:46:25.491678Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="audio" value="44100:16:2\0\u{8}\u{1}\0\0\0,\u{1}\0\0\0\0\0\0"
2023-05-27T13:46:25.491991Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:25.492005Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=17 error=false
2023-05-27T13:46:25.492021Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:25.492493Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"status")])
2023-05-27T13:46:25.492543Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:25.492675Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=238
2023-05-27T13:46:25.492736Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="volume" value="100"
2023-05-27T13:46:25.492790Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="repeat" value="0"
2023-05-27T13:46:25.492806Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="random" value="0"
2023-05-27T13:46:25.493104Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="single" value="0"
2023-05-27T13:46:25.493121Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="consume" value="0"
2023-05-27T13:46:25.493133Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="partition" value="default"
2023-05-27T13:46:25.493320Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlist" value="3"
2023-05-27T13:46:25.493336Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="playlistlength" value="2"
2023-05-27T13:46:25.493344Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="mixrampdb" value="0"
2023-05-27T13:46:25.493641Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="state" value="play"
2023-05-27T13:46:25.493658Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="song" value="1"
2023-05-27T13:46:25.493669Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="songid" value="2"
2023-05-27T13:46:25.493681Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="time" value="0:300"
2023-05-27T13:46:25.493937Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="elapsed" value="0.000"
2023-05-27T13:46:25.493998Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="bitrate" value="463"
2023-05-27T13:46:25.494013Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="duration" value="299.970"
2023-05-27T13:46:25.494191Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="audio" value="44100:16:2\0\u{8}\u{1}\0\0\0,\u{1}\0\0\0\0\0\0"
2023-05-27T13:46:25.494225Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: finished response
2023-05-27T13:46:25.494237Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: received complete response frames=1 fields=17 error=false
2023-05-27T13:46:25.494614Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:25.495038Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"currentsong")])
2023-05-27T13:46:25.495289Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"currentsong")])}: mpd_protocol::connection: sent command length=12
2023-05-27T13:46:25.496239Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: read=310
2023-05-27T13:46:25.496286Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::response: parsed field key="file" value="Crumb/Crumb/1-02. Vinta.flac"
2023-05-27T13:46:25.496339Z ERROR client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: error=invalid message
2023-05-27T13:46:25.496354Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
2023-05-27T13:46:25.496485Z  INFO mpd_discord_rpc: Detected change, updating status
2023-05-27T13:46:25.496493Z DEBUG mpd_discord_rpc: Change: SubsystemChange(Player)
2023-05-27T13:46:25.496551Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: next command immediately available command=CommandList([Command(b"status")])
2023-05-27T13:46:25.496658Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send_list{command_list=CommandList([Command(b"status")])}: mpd_protocol::connection: sent command length=7
2023-05-27T13:46:25.496726Z ERROR client connection:run loop:iteration{state=WaitingForCommandReply}:receive: mpd_protocol::connection: error=invalid message
2023-05-27T13:46:25.496740Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: response to command received
CommandError(Protocol(InvalidMessage))
2023-05-27T13:46:25.598313Z TRACE client connection:run loop:iteration{state=WaitingForCommandReply}: mpd_client::client::connection: reached next command timeout, idling
2023-05-27T13:46:25.598372Z DEBUG client connection:run loop:iteration{state=WaitingForCommandReply}:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:46:25.598394Z ERROR client connection:run loop:iteration{state=Idling}:receive: mpd_protocol::connection: error=invalid message
2023-05-27T13:46:25.598402Z TRACE client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: handling idle response
2023-05-27T13:46:25.598408Z ERROR client connection:run loop:iteration{state=Idling}: mpd_client::client::connection: state change error error=InvalidMessage
2023-05-27T13:46:25.598436Z TRACE client connection:run loop:iteration{state=Idling}: mio::poll: deregistering event source from poller
2023-05-27T13:46:25.598488Z TRACE client connection:run loop: mpd_client::client::connection: exited run_loop
2023-05-27T13:46:25.598500Z ERROR mpd_utils::persistent_client: Lost connection to 'localhost:6600': Protocol(InvalidMessage)
2023-05-27T13:46:30.599735Z TRACE mio::poll: registering event source with poller: token=Token(16777216), interests=READABLE | WRITABLE
2023-05-27T13:46:30.599867Z TRACE client connection:connect: mpd_protocol::connection: read=14
2023-05-27T13:46:30.599878Z  INFO client connection:connect: mpd_protocol::connection: connected successfully version="0.23.5"
2023-05-27T13:46:30.599897Z  INFO mpd_utils::persistent_client: Connected to 'localhost:6600'
2023-05-27T13:46:30.599902Z TRACE client connection:run loop: mpd_client::client::connection: sending initial idle command
2023-05-27T13:46:30.599920Z DEBUG client connection:run loop:send{command=Command(b"idle")}: mpd_protocol::connection: sent command length=5
2023-05-27T13:46:30.599928Z TRACE client connection:run loop: mpd_client::client::connection: entering run loop

Answer 4 · 2023-05-27T18:35:44.000Z

Mh, strange. It looks like it's failing to parse the response to the currentsong command. Could you try connecting to your MPD with telnet and showing me the output of the currentsong command? (something like telnet localhost 6600 and then typing currentsong and hitting enter).

Answer 5 · 2023-05-27T18:41:51.000Z

Ok so I just tried it and it seems to be working fine:

telnet localhost 6600
Trying ::1...
Connected to localhost.
Escape character is '^]'.
OK MPD 0.23.5
currentsong
file: Crumb/Crumb/1-02. Vinta.flac
Last-Modified: 2022-02-01T21:25:50Z���Y`H����z��8���Y`H����
Format: 44100:16:2�Q���r@
Title: Vinta
Album: Crumb
AlbumArtist: Crumb
Track: 2
Disc: 1
Artist: Crumb
Genre: Alternative, Rock
Date: 2016-09-06
Time: 300
duration: 299.970
Pos: 0
Id: 5
OK

The format and the last modified date look weird though.

Answer 6 · 2023-05-27T19:20:13.000Z

Uh, yeah. That does not look normal. The connection is aborting because the above is invalid UTF-8. I'm inclined to believe this might be an issue with MPD itself, I can't think of any reason this would happen.

Sorry for redirecting you again, but you might consider reporting an issue with MPD with the above demonstration.

Answer 7 · 2023-05-27T19:49:44.000Z

I just installed the latest MPD from the master branch I think (I did brew install mpd --HEAD) and it seems to be working fine now!

telnet localhost 6600
Trying ::1...
Connected to localhost.
Escape character is '^]'.
OK MPD 0.24.0
currentsong
file: Crumb/Crumb/1-02. Vinta.flac
Last-Modified: 2022-02-01T21:25:50Z
Format: 44100:16:2
Title: Vinta
Album: Crumb
AlbumArtist: Crumb
Track: 2
Disc: 1
Artist: Crumb
Genre: Alternative, Rock
Date: 2016-09-06
Time: 300
duration: 299.970
Pos: 1
Id: 2
OK

I also tried mpd-discord-rpc and it's working fine too. I'll just use this bleeding edge version of MPD until the 0.24 release comes out. Thanks for the help :)