Jan 26 18:31:00 keuken go-librespot[1617]: time="2026-01-26T18:31:00+01:00" level=trace msg="sent dealer ping" Jan 26 18:31:00 keuken go-librespot[1617]: time="2026-01-26T18:31:00+01:00" level=trace msg="received dealer pong" Jan 26 18:31:04 keuken volumio[1122]: verbose: New Socket.io Connection to 192.168.2.133 from 192.168.2.222 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 12 Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::volumioGetVisibleSources Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 26 18:31:04 keuken volumio[1122]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 26 18:31:04 keuken volumio[1122]: info: Received Get System Info Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 18:31:04 keuken volumio[1122]: info: Discovery: Getting this device information Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:04 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::volumioGetQueue Jan 26 18:31:04 keuken volumio[1122]: info: CoreStateMachine::getQueue Jan 26 18:31:04 keuken volumio[1122]: info: CorePlayQueue::getQueue Jan 26 18:31:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 26 18:31:05 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 26 18:31:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 26 18:31:14 keuken go-librespot[1617]: time="2026-01-26T18:31:14+01:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jan 26 18:31:14 keuken volumio[1122]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Jan 26 18:31:14 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 18:31:14 keuken volumio[1122]: Cannot find translation for source Jellyfin Jan 26 18:31:14 keuken volumio[1122]: info: Disabling plugin spop Jan 26 18:31:14 keuken volumio[1122]: info: Done. Jan 26 18:31:14 keuken volumio[1122]: info: Connection to go-librespot Websocket closed Jan 26 18:31:14 keuken sudo[13687]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Jan 26 18:31:14 keuken sudo[13687]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 18:31:14 keuken systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 26 18:31:14 keuken systemd[1]: go-librespot-daemon.service: Killing process 1627 (go-librespot) with signal SIGKILL. Jan 26 18:31:14 keuken systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 26 18:31:14 keuken systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 26 18:31:14 keuken systemd[1]: go-librespot-daemon.service: Consumed 6.286s CPU time. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:14 keuken sudo[13687]: pam_unix(sudo:session): session closed for user root Jan 26 18:31:15 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:15 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:15 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:22 keuken volumio[1122]: info: Enabling plugin spop Jan 26 18:31:22 keuken volumio[1122]: info: Loading plugin "spop"... Jan 26 18:31:22 keuken volumio[1122]: info: PLUGIN START: spop Jan 26 18:31:22 keuken volumio[1122]: info: Creating Spotify config file Jan 26 18:31:22 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 26 18:31:22 keuken volumio[1122]: info: Done. Jan 26 18:31:22 keuken volumio[1122]: info: Spotify config file written Jan 26 18:31:22 keuken volumio[1122]: info: No need to fix Spotify hosts Jan 26 18:31:22 keuken sudo[13706]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 26 18:31:22 keuken sudo[13706]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 26 18:31:22 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:9: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:22 keuken systemd[1]: /lib/systemd/system/go-librespot-daemon.service:10: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 26 18:31:22 keuken systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 26 18:31:22 keuken go-librespot[13708]: go-librespot daemon starting... Jan 26 18:31:22 keuken sudo[13706]: pam_unix(sudo:session): session closed for user root Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=info msg="running go-librespot 0.6.2" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=debug msg="app state loaded" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=debug msg="stored credentials not found" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 26 18:31:22 keuken go-librespot[13709]: time="2026-01-26T18:31:22+01:00" level=info msg="zeroconf server listening on port 32845" Jan 26 18:31:22 keuken kernel: hwmon hwmon1: Undervoltage detected! Jan 26 18:31:25 keuken volumio[1122]: info: go-librespot daemon successfully initialized Jan 26 18:31:25 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="obtained new client token: AADJmnHbMAsCqQEtuD0nzB80QWFnGtUxJc1mU4KVnOt9xGfjTq4fk/q/BfkVt9A77TLIsC7+lMNsTs6v08ro/C72pGVeMdNXY5PLhwzYzP5LdgJL+ZUydTxYxO8s6XNtKAoiVEmKGtKVqGCeRj8ClL30ICt0IBmCt8ehjbg8M9ZE9XOXcJLw2W0jp2JZBzR0gvjmhr3RJj0ETCB9hKqiSCjRqi9VgsAtGiPUbx1JA4gsXR+hszY+1wQt" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="completed keyexchange" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="completed challenge" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=info msg="authenticated AP" username="11*******74" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=info msg="authenticated Login5" username="11*******74" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=info msg="accepted zeroconf from iPhone" username="11*******74" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="dealer connection opened" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=trace msg="starting accesspoint recv loop" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=trace msg="starting dealer recv loop" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=trace msg="received accesspoint ping" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=debug msg="received connection id: NjU5M2FjMzQtYmJj...NDgxNDI1RjdEQw==" Jan 26 18:31:25 keuken go-librespot[13709]: time="2026-01-26T18:31:25+01:00" level=trace msg="received accesspoint pong ack" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=debug msg="handling transfer player command from 9ba73c2423441a0ab6b363cec9630103144fcee4" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=debug msg="resolved context of track" uri="spotify:station:album:7ampUMuhfCx0briKjYNKRQ" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:station:album:7ampUMuhfCx0briKjYNKRQ" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=trace msg="loading context page from radio-apollo/v3/tracks/spotify:station:album:7ampUMuhfCx0briKjYNKRQ?salt=802828&autoplay=false&count=50&isVideo=false&prev_tracks=4zc1kHI3oidx5AhMgqtOeV,4znKp61MTtp04IvAnmtX40,66kSq3nyISTG4FcTeeOpe2,68FhagAoZr9Ld8oCp9JoYP,13zjNPZUyWvzZC2dlYjW0L,6IGZkUyv8qCd6PCcpAzupu,3zjM3l6tM50gSNNBJ7zdAa,2xb1HCvRkwY0vof2Z6VMe9,29BQ4ugLAaXIqqu8f1gNUj,3afTrFAg0LjBVL54PiHZSP,1UhjmZcKXhl7PYtYrHKwRO,0LleMolKImXTrDwbrOB5oM,15UqRQqmOTK7DzzA235r3e,14IV6ycAWxurGj5KvHtNAT,5uNxAsQeBuRip1OCMu9HXb,7bAUUXhrZI7AIZNdhF2N3o,7uHZgfmWRqjFrC85Ou6A1I,5vVLUqs9ogEGnH44Lh8Tuc,0AMKZWRgdFfGYYTxiWrwwH,1K7Au8g0mdUzD4ve0hXUg2,0hIs6xfuaUfEKjVTVxRXv7,7aoJg1wQEqMx1t875H5fww,4mp28AMgYCgrkfJMSYtl3C,5ShdF7P8hl40IhvhoTnVyx,5pPWsSBURmhZ9VKcMMIlkV,5gSYmTVASekarEoK4puiRD,4r8uEMzIT8nlYRpKCqDVNG,3zh5km8gPDYMiWvmLTsos0,0QYLrwHg7e0ZjInsO3f1uh,1vEWp2y4RTmsoKE6piDIPk,4cOtcRXI3a2v1gEsI1Meeo,37pK088xTo1ZpR3y23wsFk,02cCntRCrtgojL45e9oNnu,7uCYyqkND086wKanPTbBP0,5hLiMgK0oIx8t9AwO3Pm3P,1oAs44xVvu4QaZpX9033S5,3URb74mrpnRWY1HtTBEUKH,3k8WOOIt8iHgfXzTXBonDC,6ydqEdlzueCGmQE2oosecr,3vTAheX6bBX0hpVMBvE9l0,2HDdFE3LzgZ2ZWVXS0jEQF,32nKx3A89Lic6UcWy3ePsy,5oPWYCHejJF8Jwj3hiaTeh,1WWVlkmJSdLBSiqF2m8Ex2,3bWvZ3YluJBtHgCP7c0tBv,7i9RIEuPvpQ8NtfI0dSJeK,4IVyX0UJzGyUk0MLiz1jVJ,3rD35vM72SUnFnHRPbpEIp,0suRVpl5fIZVm7PuROSRsQ,0XfG2TiokNKrRSnzcLlz3W&minimal=true" uri="spotify:station:album:7ampUMuhfCx0briKjYNKRQ" Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:26 keuken go-librespot[13709]: time="2026-01-26T18:31:26+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:27 keuken go-librespot[13709]: time="2026-01-26T18:31:27+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:28 keuken volumio[1122]: info: Initializing connection to go-librespot Websocket Jan 26 18:31:28 keuken go-librespot[13709]: time="2026-01-26T18:31:28+01:00" level=debug msg="new websocket client" Jan 26 18:31:28 keuken volumio[1122]: info: Connection to go-librespot Websocket established Jan 26 18:31:28 keuken go-librespot[13709]: time="2026-01-26T18:31:28+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:29 keuken kernel: hwmon hwmon1: Voltage normalised Jan 26 18:31:29 keuken ntpd[959]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 18:31:29 keuken ntpd[959]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Jan 26 18:31:29 keuken ntpd[959]: DNS: Pool skipping: 192.168.2.1 Jan 26 18:31:29 keuken ntpd[959]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Jan 26 18:31:30 keuken go-librespot[13709]: time="2026-01-26T18:31:30+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:31 keuken volumio[1122]: info: Getting Spotify volume Jan 26 18:31:31 keuken volumio[1122]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jan 26 18:31:31 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:31 keuken volumio[1122]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 26 18:31:33 keuken go-librespot[13709]: time="2026-01-26T18:31:33+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:35 keuken ntpd[959]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 18:31:35 keuken ntpd[959]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Jan 26 18:31:35 keuken ntpd[959]: DNS: Pool skipping: 192.168.2.1 Jan 26 18:31:35 keuken ntpd[959]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Jan 26 18:31:35 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:35 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:35 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:36 keuken ntpd[959]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 18:31:36 keuken ntpd[959]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Jan 26 18:31:36 keuken ntpd[959]: DNS: Pool skipping: 192.168.2.1 Jan 26 18:31:36 keuken ntpd[959]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Jan 26 18:31:37 keuken ntpd[959]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Jan 26 18:31:37 keuken ntpd[959]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Jan 26 18:31:37 keuken ntpd[959]: DNS: Pool skipping: 192.168.2.1 Jan 26 18:31:37 keuken ntpd[959]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Jan 26 18:31:38 keuken go-librespot[13709]: time="2026-01-26T18:31:38+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:44 keuken go-librespot[13709]: time="2026-01-26T18:31:44+01:00" level=debug msg="spclient request returned bad gateway, retrying..." Jan 26 18:31:45 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:52 keuken volumio[1122]: verbose: New Socket.io Connection to 192.168.2.133 from 192.168.2.222 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 11 Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::volumioGetVisibleSources Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 26 18:31:52 keuken volumio[1122]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 26 18:31:52 keuken volumio[1122]: info: Received Get System Info Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 26 18:31:52 keuken volumio[1122]: info: Discovery: Getting this device information Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:52 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::volumioGetQueue Jan 26 18:31:52 keuken volumio[1122]: info: CoreStateMachine::getQueue Jan 26 18:31:52 keuken volumio[1122]: info: CorePlayQueue::getQueue Jan 26 18:31:52 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 26 18:31:54 keuken kernel: hwmon hwmon1: Undervoltage detected! Jan 26 18:31:55 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:31:55 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:55 keuken volumio[1122]: info: Listing playlists Jan 26 18:31:55 keuken go-librespot[13709]: time="2026-01-26T18:31:55+01:00" level=trace msg="sent dealer ping" Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=warning msg="failed seeking to track in context spotify:station:album:7ampUMuhfCx0briKjYNKRQ" error="failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: failed requesting page at radio-apollo/v3/tracks/spotify:station:album:7ampUMuhfCx0briKjYNKRQ?salt=802828&autoplay=false&count=50&isVideo=false&prev_tracks=4zc1kHI3oidx5AhMgqtOeV,4znKp61MTtp04IvAnmtX40,66kSq3nyISTG4FcTeeOpe2,68FhagAoZr9Ld8oCp9JoYP,13zjNPZUyWvzZC2dlYjW0L,6IGZkUyv8qCd6PCcpAzupu,3zjM3l6tM50gSNNBJ7zdAa,2xb1HCvRkwY0vof2Z6VMe9,29BQ4ugLAaXIqqu8f1gNUj,3afTrFAg0LjBVL54PiHZSP,1UhjmZcKXhl7PYtYrHKwRO,0LleMolKImXTrDwbrOB5oM,15UqRQqmOTK7DzzA235r3e,14IV6ycAWxurGj5KvHtNAT,5uNxAsQeBuRip1OCMu9HXb,7bAUUXhrZI7AIZNdhF2N3o,7uHZgfmWRqjFrC85Ou6A1I,5vVLUqs9ogEGnH44Lh8Tuc,0AMKZWRgdFfGYYTxiWrwwH,1K7Au8g0mdUzD4ve0hXUg2,0hIs6xfuaUfEKjVTVxRXv7,7aoJg1wQEqMx1t875H5fww,4mp28AMgYCgrkfJMSYtl3C,5ShdF7P8hl40IhvhoTnVyx,5pPWsSBURmhZ9VKcMMIlkV,5gSYmTVASekarEoK4puiRD,4r8uEMzIT8nlYRpKCqDVNG,3zh5km8gPDYMiWvmLTsos0,0QYLrwHg7e0ZjInsO3f1uh,1vEWp2y4RTmsoKE6piDIPk,4cOtcRXI3a2v1gEsI1Meeo,37pK088xTo1ZpR3y23wsFk,02cCntRCrtgojL45e9oNnu,7uCYyqkND086wKanPTbBP0,5hLiMgK0oIx8t9AwO3Pm3P,1oAs44xVvu4QaZpX9033S5,3URb74mrpnRWY1HtTBEUKH,3k8WOOIt8iHgfXzTXBonDC,6ydqEdlzueCGmQE2oosecr,3vTAheX6bBX0hpVMBvE9l0,2HDdFE3LzgZ2ZWVXS0jEQF,32nKx3A89Lic6UcWy3ePsy,5oPWYCHejJF8Jwj3hiaTeh,1WWVlkmJSdLBSiqF2m8Ex2,3bWvZ3YluJBtHgCP7c0tBv,7i9RIEuPvpQ8NtfI0dSJeK,4IVyX0UJzGyUk0MLiz1jVJ,3rD35vM72SUnFnHRPbpEIp,0suRVpl5fIZVm7PuROSRsQ,0XfG2TiokNKrRSnzcLlz3W&minimal=true: spclient request failed: context deadline exceeded" uri="spotify:station:album:7ampUMuhfCx0briKjYNKRQ" Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:4zc1kHI3oidx5AhMgqtOeV" Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=error msg="failed put state after update" error="context deadline exceeded" Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=trace msg="emitting websocket event: will_play" Jan 26 18:31:56 keuken volumio[1122]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:station:album:7ampUMuhfCx0briKjYNKRQ","uri":"spotify:track:4zc1kHI3oidx5AhMgqtOeV","play_origin":""}} Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=warning msg="failed handling dealer request" error="failed loading current track (transfer): failed creating stream for spotify:track:4zc1kHI3oidx5AhMgqtOeV: failed getting track metadata: spclient request failed: context deadline exceeded" Jan 26 18:31:56 keuken go-librespot[13709]: time="2026-01-26T18:31:56+01:00" level=trace msg="received dealer pong" Jan 26 18:31:56 keuken volumio[1122]: info: Spotify volume: 100 Jan 26 18:31:58 keuken kernel: hwmon hwmon1: Voltage normalised Jan 26 18:31:59 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 26 18:31:59 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 26 18:32:04 keuken volumio[1122]: info: Executing endpoint metavolumio Jan 26 18:32:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 18:32:04 keuken volumio[1122]: info: Executing endpoint metavolumio Jan 26 18:32:04 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 26 18:32:05 keuken volumio[1122]: info: CoreCommandRouter::volumioGetState Jan 26 18:32:08 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 26 18:32:08 keuken volumio[1122]: info: Preload queue cleared Jan 26 18:32:10 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri Jan 26 18:32:10 keuken volumio[1122]: info: Preload queue cleared Jan 26 18:32:11 keuken volumio[1122]: info: Preload queue cleared Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::ClearQueue Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::stop Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::updateTrackBlock Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrackBlock Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::stPlaybackTimer Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::pushState Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrack 0 Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioPushState Jan 26 18:32:11 keuken volumio[1122]: info: MRS: Pushing multiroomSync output update for this device Jan 26 18:32:11 keuken volumio[1122]: info: MRS: Pushing multiroomSync output Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::serviceStop Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrack 0 Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::serviceStop Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 26 18:32:11 keuken volumio[1122]: info: ControllerMpd::stop Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::clearPlayQueue Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::saveQueue Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioPushQueue Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::addQueueItems Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::addQueueItems Jan 26 18:32:11 keuken volumio[1122]: info: Preload queue cleared Jan 26 18:32:11 keuken volumio[1122]: info: Adding Item to queue: https://icecast.radiofrance.fr/fip-hifi.aac?id=radiofrance Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioPushQueue Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::saveQueue Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::updateTrackBlock Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrackBlock Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioPlay Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::play index 0 Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::stop Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::play index undefined Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrack 0 Jan 26 18:32:11 keuken volumio[1122]: info: CoreStateMachine::startPlaybackTimer Jan 26 18:32:11 keuken volumio[1122]: info: CorePlayQueue::getTrack 0 Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::volumioGetVisibleSources Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 26 18:32:11 keuken volumio[1122]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 26 18:32:11 keuken volumio[1122]: info: [1769448731343] ControllerWebradio::clearAddPlayTrack Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand stop Jan 26 18:32:11 keuken volumio[1122]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Jan 26 18:32:11 keuken volumio[1122]: SPOTIFY: SPOTIFY VOLUME 100 Jan 26 18:32:11 keuken volumio[1122]: SPOTIFY: VOLUMIO VOLUME 35 Jan 26 18:32:11 keuken volumio[1122]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 26 18:32:11 keuken volumio[1122]: info: Setting Spotify Volume from Volumio: 35 Jan 26 18:32:11 keuken volumio[1122]: info: ControllerMpd::getState Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand status Jan 26 18:32:11 keuken volumio[1122]: info: Jan 26 18:32:11 keuken volumio[1122]: ---------------------------- MPD announces state update: player Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand stop took 27 milliseconds Jan 26 18:32:11 keuken volumio[1122]: info: ControllerMpd::getState Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand status Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand stop took 13 milliseconds Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand clear Jan 26 18:32:11 keuken volumio[1122]: info: Jan 26 18:32:11 keuken volumio[1122]: ---------------------------- MPD announces system playlist update Jan 26 18:32:11 keuken volumio[1122]: info: Ignoring MPD Status Update Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand status took 3 milliseconds Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand status took 2 milliseconds Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand clear took 1 milliseconds Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::parseState Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::parseState Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::sendMpdCommand load "https://icecast.radiofrance.fr/fip-hifi.aac?id=radiofrance" Jan 26 18:32:11 keuken volumio[1122]: error: updateQueue error: null Jan 26 18:32:11 keuken volumio[1122]: info: ------------------------------ 3ms Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 18:32:11 keuken volumio[1122]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::parseTrackInfo Jan 26 18:32:11 keuken volumio[1122]: verbose: ControllerMpd::parseTrackInfo Jan 26 18:32:11 keuken volumio[1122]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Jan 26 18:32:11 keuken volumio[1122]: info: ------------------------------ 8ms Jan 26 18:32:11 keuken volumio[1122]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 18:32:11 keuken volumio[1122]: TypeError: Cannot read properties of undefined (reading 'split') Jan 26 18:32:11 keuken volumio[1122]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) Jan 26 18:32:11 keuken volumio[1122]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 26 18:32:11 keuken volumio[1122]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jan 26 18:32:11 keuken volumio[1122]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 26 18:32:11 keuken sudo[13823]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-26 18:31' Jan 26 18:32:11 keuken sudo[13823]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"