Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: ---------------------------- MPD announces system playlist update Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Ignoring MPD Status Update Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: ---------------------------- MPD announces state update: player Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ControllerMpd::getState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: ---------------------------- MPD announces system playlist update Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Ignoring MPD Status Update Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: ---------------------------- MPD announces state update: player Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ControllerMpd::getState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::sendMpdCommand status Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ------------------------------ 13ms Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: sendMpdCommand status took 12 milliseconds Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ------------------------------ 11ms Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: sendMpdCommand status took 11 milliseconds Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::parseState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::parseState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: verbose: ControllerMpd::parseTrackInfo Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ControllerMpd::pushState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: CorePlayQueue::getTrack 0 Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ControllerMpd::pushState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: CorePlayQueue::getTrack 0 Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ------------------------------ 16ms Oct 11 14:57:42 31d-music-station-2026 volumio[1089]: info: ------------------------------ 15ms Oct 11 14:58:11 31d-music-station-2026 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Oct 11 14:58:12 31d-music-station-2026 systemd[1]: setdatetime-helper.service: Deactivated successfully. Oct 11 14:58:12 31d-music-station-2026 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="obtained new client token: AAFwRrqV8uuNpLaK9Coypi5FgL4xhwXxZScgWFwuM0p2BF/zDA46IknWa4ttxyhmG2lO1kwKytcnL+2Mty9hwaAfCtYo49iNoOlQIFncOihVpFBYIEHm+uud0OCnRgc6yO6pW6E+Qf5EpgeQlQXqJO1LsJ7js3RFVxzSG/DE8PQg30T3IQFLQi67rREzJqXRPEEZ/rldON/ifhOL/O+OuQdrKAgAFOJzhpSTW8sp/aWf8M+ItTcwP5U=" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="completed keyexchange" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="completed challenge" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=info msg="authenticated AP" username="cb***le" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=info msg="authenticated Login5" username="cb***le" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="persisted zeroconf credentials" username="cb***le" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=info msg="accepted zeroconf from iPhone" username="cb***le" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="connected to gue1-dealer.spotify.com:443" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=trace msg="starting accesspoint recv loop" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=trace msg="starting dealer recv loop" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="received connection id: NjY0MTZmNzctOWJk...RkUzQjgxNjc3OQ==" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="skipping dealer message" uri="ap://product-state-update" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="put connect state because NEW_DEVICE" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=trace msg="emitting websocket event: playback_ready" Oct 11 14:58:13 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"playback_ready","data":null} Oct 11 14:58:13 31d-music-station-2026 volumio[1089]: error: Failed to decode event: playback_ready Oct 11 14:58:13 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"playback_ready","data":null} Oct 11 14:58:13 31d-music-station-2026 volumio[1089]: error: Failed to decode event: playback_ready Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="handling transfer player command from 00b5573395c06ee8056d1db5d97c91d824d86a73" Oct 11 14:58:13 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:13-04:00" level=debug msg="resolved context of track" uri="spotify:user:cbottle:collection" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="fetched new page 0 with 78 items (list: 78)" uri="spotify:user:cbottle:collection" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="loading track (paused: false, position: 68421ms)" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="emitting websocket event: will_play" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:user:cbottle:collection","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","play_origin":"connect"}} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:user:cbottle:collection","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","play_origin":"connect"}} Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 450" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="selected format OGG_VORBIS_320 (d95c03336fff15ae709583af17c3b41751c7a56e)" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="requested aes key for file d95c03336fff15ae709583af17c3b41751c7a56e, gid: 1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1527" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 450" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched first chunk of 19, total size is 9570540 bytes" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1284" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="seek to 68421ms (diff: 85ms, samples: 3017366, bytes: 3186044)" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="track has no narration" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="created new output device" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=info msg="loaded track \"Keep Me in Your Heart\" (paused: false, position: 68421ms, duration: 208026ms, prefetched: false)" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="scheduling prefetch in 110s" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="emitting websocket event: metadata" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"metadata","data":{"album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","album_name":"The Wind","artist_names":["Warren Zevon"],"bit_depth":null,"bitrate":320,"codec":"vorbis","disc_number":1,"duration":208026,"format":"OGG_VORBIS_320","name":"Keep Me in Your Heart","position":68421,"release_date":"year:2003 month:8 day:26","sample_rate":44100,"track_number":11,"uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ"}} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"metadata","data":{"album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","album_name":"The Wind","artist_names":["Warren Zevon"],"bit_depth":null,"bitrate":320,"codec":"vorbis","disc_number":1,"duration":208026,"format":"OGG_VORBIS_320","name":"Keep Me in Your Heart","position":68421,"release_date":"year:2003 month:8 day:26","sample_rate":44100,"track_number":11,"uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ"}} Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="emitting websocket event: active" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="sending successful reply for dealer request" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"active","data":null} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Aligning Spotify Volume to Volumio Volume Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CorePlayQueue::getTrack 0 Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Setting Spotify Volume from Volumio: 86 Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"active","data":null} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Aligning Spotify Volume to Volumio Volume Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioGetState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CorePlayQueue::getTrack 0 Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Setting Spotify Volume from Volumio: 86 Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=trace msg="emitting websocket event: playing" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:user:cbottle:collection","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","resume":false,"play_origin":"connect"}} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Spotify is playing in volatile mode Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: UNSET VOLATILE Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","position":0,"title":"Rick Springfield - Celebrate Youth","artist":"80s80s Real 80s Radio","album":"","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music124/v4/31/b7/6c/31b76ce4-cff7-6a98-4490-8ee4dba569e6/source/600x600bb.jpg","uri":"http://streams.80s80s.de/web/mp3-192/volumio","trackType":"80s80s Radio","seek":0,"duration":"230","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":86,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Setting Spotify stop after unset volatile call Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: PUSH STATE SPOTIFY Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","service":"spop","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::pushState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.920Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.923Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.923Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.924Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:user:cbottle:collection","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","resume":false,"play_origin":"connect"}} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Spotify is playing in volatile mode Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: UNSET VOLATILE Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","position":0,"title":"Rick Springfield - Celebrate Youth","artist":"80s80s Real 80s Radio","album":"","albumart":"https://is5-ssl.mzstatic.com/image/thumb/Music124/v4/31/b7/6c/31b76ce4-cff7-6a98-4490-8ee4dba569e6/source/600x600bb.jpg","uri":"http://streams.80s80s.de/web/mp3-192/volumio","trackType":"80s80s Radio","seek":0,"duration":"230","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":86,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: Setting Spotify stop after unset volatile call Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: PUSH STATE SPOTIFY Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","service":"spop","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::pushState Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.937Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.938Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.939Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:14 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:14.952Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:14 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:14 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:14-04:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: PUSH STATE SPOTIFY Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","service":"spop","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::pushState Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.214Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.215Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.216Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.216Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: PUSH STATE SPOTIFY Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","service":"spop","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::servicePushState Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreStateMachine::pushState Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: CoreCommandRouter::volumioPushState Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.232Z level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.233Z level=INFO msg="emitting player state changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" state=STATUS_PLAYING positionMs=68421 volume=86 Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.234Z level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.0.123:50928 @ 0x1cbbd70" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:15 31d-music-station-2026 volumio5-onboarding[1287]: time=2026-10-11T18:58:15.236Z level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.123:50928 @ 0x1c00ed0" id=spotify:track:1fRlDQzrpvWd4BlIzifUkJ title="Keep Me in Your Heart" Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: Spotify Stop Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: SPOTIFY STOP Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","codec":"ogg","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":86,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: info: Spotify Stop Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: SPOTIFY STOP Oct 11 14:58:15 31d-music-station-2026 volumio[1089]: SPOTIFY: {"status":"play","title":"Keep Me in Your Heart","artist":"Warren Zevon","album":"The Wind","albumart":"https://i.scdn.co/image/ab67616d00001e02e34f4cd4c206759b13bfb53c","uri":"spotify:track:1fRlDQzrpvWd4BlIzifUkJ","trackType":"spotify","codec":"ogg","seek":68421,"duration":208,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":86,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Oct 11 14:58:15 31d-music-station-2026 go-librespot[7709]: time="2026-10-11T14:58:15-04:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:1fRlDQzrpvWd4BlIzifUkJ" Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: info: [1791745096184] [80s80s] Pushing the next song state Mental As Anything - Live It Up and getting next track. Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: TypeError: Cannot set properties of undefined (setting 'name') Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: at process.processImmediate (node:internal/timers:478:21) Oct 11 14:58:16 31d-music-station-2026 volumio[1089]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 14:58:18 31d-music-station-2026 sudo[11961]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-11 14:57' Oct 11 14:58:18 31d-music-station-2026 sudo[11961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"