-- Logs begin at Thu 2019-02-14 12:11:59 EET, end at Tue 2026-03-24 23:36:54 EET. -- Mar 24 23:35:04 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:35:04 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 24 23:35:18 volumio volumio[1306]: info: Enabling plugin spop Mar 24 23:35:18 volumio volumio[1306]: info: Loading plugin "spop"... Mar 24 23:35:18 volumio volumio[1306]: info: PLUGIN START: spop Mar 24 23:35:18 volumio volumio[1306]: info: Creating Spotify config file Mar 24 23:35:18 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 24 23:35:18 volumio volumio[1306]: info: Done. Mar 24 23:35:18 volumio volumio[1306]: info: Spotify config file written Mar 24 23:35:18 volumio volumio[1306]: info: No need to fix Spotify hosts Mar 24 23:35:18 volumio sudo[32190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 24 23:35:18 volumio sudo[32190]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 23:35:18 volumio systemd[1]: Stopping go-librespot Daemon... Mar 24 23:35:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Mar 24 23:35:18 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Mar 24 23:35:18 volumio systemd[1]: Stopped go-librespot Daemon. Mar 24 23:35:18 volumio volumio[1306]: info: Connection to go-librespot Websocket closed Mar 24 23:35:18 volumio volumio[1306]: info: Connection to go-librespot Websocket closed Mar 24 23:35:18 volumio systemd[1]: Started go-librespot Daemon. Mar 24 23:35:18 volumio go-librespot[32192]: go-librespot daemon starting... Mar 24 23:35:18 volumio sudo[32190]: pam_unix(sudo:session): session closed for user root Mar 24 23:35:18 volumio go-librespot[32192]: time="2026-03-24T23:35:18+02:00" level=info msg="running go-librespot 0.7.1" Mar 24 23:35:18 volumio go-librespot[32192]: time="2026-03-24T23:35:18+02:00" level=debug msg="app state loaded" Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 24 23:35:19 volumio volumio[1306]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 24 23:35:19 volumio volumio[1306]: SPOTIFY: BQB19pEMwJdJ8YEuNoM0fIUG63kMVDwYtNjNrzQ_USLz2PDHsPRgm0YrHxhpAerJfepYuEbLnnx3FM1P2WmCrMZBaxyM9tpEvZT8gErlHwK5gYzMHCCJIIXT_LN0wGxTHbP1AJS7lr5hWdejJ_93meCIhbl_M6sUnPyEPpwdB8tvOI_HQRjSIK7Z-Y6Cxa-IGtwimwPmXfh17R3tOfeXFLhOsmfvIRQMreRo8PZuLjHTmOHuz_6oBJhtu-SYNnKubPZH5LvoZbIVjIJvb7uatJ_9iCTQNauKOwCTjT7cIIHzPhwbfuameHLTcw Mar 24 23:35:19 volumio volumio[1306]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Mar 24 23:35:19 volumio volumio[1306]: info: New Spotify access token = BQB19pEMwJdJ8YEuNoM0fIUG63kMVDwYtNjNrzQ_USLz2PDHsPRgm0YrHxhpAerJfepYuEbLnnx3FM1P2WmCrMZBaxyM9tpEvZT8gErlHwK5gYzMHCCJIIXT_LN0wGxTHbP1AJS7lr5hWdejJ_93meCIhbl_M6sUnPyEPpwdB8tvOI_HQRjSIK7Z-Y6Cxa-IGtwimwPmXfh17R3tOfeXFLhOsmfvIRQMreRo8PZuLjHTmOHuz_6oBJhtu-SYNnKubPZH5LvoZbIVjIJvb7uatJ_9iCTQNauKOwCTjT7cIIHzPhwbfuameHLTcw Mar 24 23:35:19 volumio volumio[1306]: info: Spotify credentials grant success - running version from March 24, 2019 Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02: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]" Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02: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]" Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02: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]" Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02:00" level=info msg="zeroconf server listening on port 43521" Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02:00" level=info msg="using avahi-daemon avahi 0.7 for mDNS service registration" Mar 24 23:35:19 volumio volumio[1306]: SPOTIFY: User informations: {"country":"GR","display_name":"Mc Lucifer","email":"lucifer.mobile.gr@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/0t4fx3rz3ctpghq2wjd63af1k"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/0t4fx3rz3ctpghq2wjd63af1k","id":"0t4fx3rz3ctpghq2wjd63af1k","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85b99e2d56d6f5197211a11a78","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82b99e2d56d6f5197211a11a78","width":64}],"product":"premium","type":"user","uri":"spotify:user:0t4fx3rz3ctpghq2wjd63af1k"} Mar 24 23:35:19 volumio volumio[1306]: info: Spotify Successfully logged in Mar 24 23:35:19 volumio volumio[1306]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 24 23:35:19 volumio volumio[1306]: info: [1774388119858] CoreMusicLibrary::Adding element Spotify Mar 24 23:35:19 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:35:19 volumio volumio[1306]: Cannot find translation for source SoundCloud Mar 24 23:35:19 volumio volumio[1306]: Cannot find translation for source 80s80s Radio Mar 24 23:35:19 volumio volumio[1306]: Cannot find translation for source Mother Earth Radio Mar 24 23:35:19 volumio volumio[1306]: Cannot find translation for source Radio Paradise Mar 24 23:35:19 volumio volumio[1306]: Cannot find translation for source Spotify Mar 24 23:35:19 volumio go-librespot[32192]: time="2026-03-24T23:35:19+02:00" level=debug msg="obtained new client token: AAAUzgYs9NEYguLrQo3gEiZCoflAQxxh5TyYlrLxJE4wKGMiFZwHemcyPFXuAUlbqShD3d1mKMIU0S7yhEwsK6AF4sSrz9wIfWWMeXGgjD5jpXeGLxEyd3M5Ao1xQoevA5jWLERzWETaBRLvG6UtzCdvOtYeiL0V/6z04o2Pms4RbdQFDvjxB7NdY4YNH/4oM/KHSSxCInScyqt2D/rPRWHSw8kfjMOzhj9iL6Hgs5shh39KZioLt/z6" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=debug msg="completed keyexchange" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=debug msg="completed challenge" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=info msg="authenticated AP" username="0t*********************1k" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=info msg="authenticated Login5" username="0t*********************1k" Mar 24 23:35:20 volumio go-librespot[32192]: time="2026-03-24T23:35:20+02:00" level=debug msg="initializing zeroconf session" username="0t*********************1k" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="dealer connection opened" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=trace msg="starting accesspoint recv loop" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=trace msg="starting dealer recv loop" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=trace msg="received accesspoint ping" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="received connection id: MWRlMWQ3OTgtOGVk...MEZCNzY4RTdBRQ==" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=trace msg="received accesspoint pong ack" Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="put connect state because NEW_DEVICE" Mar 24 23:35:21 volumio volumio[1306]: info: Initializing connection to go-librespot Websocket Mar 24 23:35:21 volumio go-librespot[32192]: time="2026-03-24T23:35:21+02:00" level=debug msg="new websocket client" Mar 24 23:35:21 volumio volumio[1306]: info: Connection to go-librespot Websocket established Mar 24 23:35:21 volumio volumio[1306]: info: go-librespot daemon successfully initialized Mar 24 23:35:24 volumio volumio[1306]: info: Getting Spotify volume Mar 24 23:35:24 volumio volumio[1306]: info: Spotify volume: 100 Mar 24 23:35:24 volumio volumio[1306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:35:24 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:35:24 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Mar 24 23:35:24 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:24 volumio volumio[1306]: info: Initializing connection to go-librespot Websocket Mar 24 23:35:24 volumio go-librespot[32192]: time="2026-03-24T23:35:24+02:00" level=debug msg="new websocket client" Mar 24 23:35:24 volumio volumio[1306]: info: Connection to go-librespot Websocket established Mar 24 23:35:27 volumio volumio[1306]: info: Getting Spotify volume Mar 24 23:35:27 volumio volumio[1306]: info: Spotify volume: 100 Mar 24 23:35:27 volumio volumio[1306]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:35:27 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:35:27 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Mar 24 23:35:28 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:30 volumio go-librespot[32192]: time="2026-03-24T23:35:30+02:00" level=debug msg="skipping dealer message" uri="ap://product-state-update" Mar 24 23:35:36 volumio go-librespot[32192]: time="2026-03-24T23:35:36+02:00" level=debug msg="handling transfer player command from e8caa405f615ced6220e18b42b40910f8a647ec6" Mar 24 23:35:36 volumio go-librespot[32192]: time="2026-03-24T23:35:36+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:3CoXk99S2orNNWfs0PWEez" Mar 24 23:35:36 volumio go-librespot[32192]: time="2026-03-24T23:35:36+02:00" level=trace msg="fetched new page 0 with 17 items (list: 17)" uri="spotify:playlist:3CoXk99S2orNNWfs0PWEez" Mar 24 23:35:36 volumio go-librespot[32192]: time="2026-03-24T23:35:36+02:00" level=debug msg="loading track (paused: true, position: 76782ms)" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=trace msg="emitting websocket event: will_play" Mar 24 23:35:37 volumio volumio[1306]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:3CoXk99S2orNNWfs0PWEez","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","play_origin":"playlist"}} Mar 24 23:35:37 volumio volumio[1306]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:3CoXk99S2orNNWfs0PWEez","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","play_origin":"playlist"}} Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1716" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="selected format OGG_VORBIS_320 (d3238958ad9b8b871d735a1eee502e07546ca82c)" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="requested aes key for file d3238958ad9b8b871d735a1eee502e07546ca82c, gid: 1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 162" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1311" Mar 24 23:35:37 volumio go-librespot[32192]: time="2026-03-24T23:35:37+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:38 volumio go-librespot[32192]: time="2026-03-24T23:35:38+02:00" level=debug msg="fetched first chunk of 17, total size is 8808388 bytes" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:38 volumio go-librespot[32192]: time="2026-03-24T23:35:38+02:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:38 volumio go-librespot[32192]: time="2026-03-24T23:35:38+02:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="fetched chunk 6/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="fetched chunk 5/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="fetched chunk 7/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=trace msg="seek to 76782ms (diff: 164ms, samples: 3386086, bytes: 2942611)" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="created new output device" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=info msg="loaded track \"Justice's Groove\" (paused: true, position: 76782ms, duration: 228333ms, prefetched: false)" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="fetched chunk 8/16, size: 524288" uri="spotify:track:1UCxSr21ISkR4HR1Wom8U8" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=trace msg="emitting websocket event: metadata" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=trace msg="emitting websocket event: active" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="sending successful reply for dealer request" Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","name":"Justice's Groove","artist_names":["Stanley Clarke"],"album_name":"At The Movies","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","position":76782,"duration":228333,"release_date":"year:1995 month:7 day:14","track_number":3,"disc_number":1}} Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"active","data":null} Mar 24 23:35:39 volumio volumio[1306]: info: Aligning Spotify Volume to Volumio Volume Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:35:39 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Mar 24 23:35:39 volumio volumio[1306]: info: Setting Spotify Volume from Volumio: 100 Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","name":"Justice's Groove","artist_names":["Stanley Clarke"],"album_name":"At The Movies","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","position":76782,"duration":228333,"release_date":"year:1995 month:7 day:14","track_number":3,"disc_number":1}} Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"active","data":null} Mar 24 23:35:39 volumio volumio[1306]: info: Aligning Spotify Volume to Volumio Volume Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:35:39 volumio volumio[1306]: info: CorePlayQueue::getTrack 0 Mar 24 23:35:39 volumio volumio[1306]: info: Setting Spotify Volume from Volumio: 100 Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:39 volumio go-librespot[32192]: time="2026-03-24T23:35:39+02:00" level=trace msg="emitting websocket event: paused" Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:3CoXk99S2orNNWfs0PWEez","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","play_origin":"playlist"}} Mar 24 23:35:39 volumio volumio[1306]: info: Spotify is playing in volatile mode Mar 24 23:35:39 volumio volumio[1306]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: UNSET VOLATILE Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: {"status":"play","position":0,"title":"Prince - If I Was Your Girlfriend","artist":"80s80s Prince","album":"","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music114/v4/69/33/e5/6933e58f-9e03-e994-59f0-4c561ff35028/source/600x600bb.jpg","uri":"http://streams.80s80s.de/100/mp3-192/volumio","trackType":"80s80s Radio","seek":195184,"duration":"281","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Mar 24 23:35:39 volumio volumio[1306]: info: Setting Spotify stop after unset volatile call Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Justice's Groove","artist":"Stanley Clarke","album":"At The Movies","albumart":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","trackType":"spotify","seek":76782,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:39 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.605+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=76782 volume=100 Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.605+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=76782 volume=100 Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.606+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1UCxSr21ISkR4HR1Wom8U8 title="Justice's Groove" Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.606+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1UCxSr21ISkR4HR1Wom8U8 title="Justice's Groove" Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:3CoXk99S2orNNWfs0PWEez","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","play_origin":"playlist"}} Mar 24 23:35:39 volumio volumio[1306]: info: Spotify is playing in volatile mode Mar 24 23:35:39 volumio volumio[1306]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: UNSET VOLATILE Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: {"status":"play","position":0,"title":"Prince - If I Was Your Girlfriend","artist":"80s80s Prince","album":"","albumart":"https://is1-ssl.mzstatic.com/image/thumb/Music114/v4/69/33/e5/6933e58f-9e03-e994-59f0-4c561ff35028/source/600x600bb.jpg","uri":"http://streams.80s80s.de/100/mp3-192/volumio","trackType":"80s80s Radio","seek":195184,"duration":"281","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Mar 24 23:35:39 volumio volumio[1306]: info: Setting Spotify stop after unset volatile call Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Justice's Groove","artist":"Stanley Clarke","album":"At The Movies","albumart":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","trackType":"spotify","seek":76782,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:39 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:39 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.615+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=76782 volume=100 Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.615+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=76782 volume=100 Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.616+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1UCxSr21ISkR4HR1Wom8U8 title="Justice's Groove" Mar 24 23:35:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:39.616+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1UCxSr21ISkR4HR1Wom8U8 title="Justice's Groove" Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:39 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:40 volumio volumio[1306]: info: Spotify Stop Mar 24 23:35:40 volumio volumio[1306]: SPOTIFY: SPOTIFY STOP Mar 24 23:35:40 volumio volumio[1306]: SPOTIFY: {"status":"pause","title":"Justice's Groove","artist":"Stanley Clarke","album":"At The Movies","albumart":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","trackType":"spotify","codec":"ogg","seek":76782,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Mar 24 23:35:40 volumio volumio[1306]: info: Spotify Stop Mar 24 23:35:40 volumio volumio[1306]: SPOTIFY: SPOTIFY STOP Mar 24 23:35:40 volumio volumio[1306]: SPOTIFY: {"status":"pause","title":"Justice's Groove","artist":"Stanley Clarke","album":"At The Movies","albumart":"https://i.scdn.co/image/ab67616d00001e02912afd27aa7de27d83c4ce95","uri":"spotify:track:1UCxSr21ISkR4HR1Wom8U8","trackType":"spotify","codec":"ogg","seek":76782,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Mar 24 23:35:40 volumio volumio[1306]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Mar 24 23:35:40 volumio volumio[1306]: info: Sending Spotify command with payload to local API: /player/volume Mar 24 23:35:40 volumio go-librespot[32192]: time="2026-03-24T23:35:40+02:00" level=debug msg="update volume requested to 65535/65535" Mar 24 23:35:41 volumio go-librespot[32192]: time="2026-03-24T23:35:41+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 24 23:35:41 volumio go-librespot[32192]: time="2026-03-24T23:35:41+02:00" level=trace msg="emitting websocket event: volume" Mar 24 23:35:41 volumio volumio[1306]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Mar 24 23:35:41 volumio volumio[1306]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Mar 24 23:35:41 volumio volumio[1306]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Mar 24 23:35:41 volumio volumio[1306]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="handling play player command from e8caa405f615ced6220e18b42b40910f8a647ec6" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="resolved context of track" uri="spotify:album:097eYvf9NKjFnv4xA9s2oV" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=trace msg="fetched new page 0 with 11 items (list: 11)" uri="spotify:album:097eYvf9NKjFnv4xA9s2oV" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=trace msg="emitting websocket event: will_play" Mar 24 23:35:43 volumio volumio[1306]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:35:43 volumio volumio[1306]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="selected format OGG_VORBIS_320 (c3ec096907b4384057a634d4ef3fe72a6ecbe30a)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=debug msg="requested aes key for file c3ec096907b4384057a634d4ef3fe72a6ecbe30a, gid: 1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:43 volumio go-librespot[32192]: time="2026-03-24T23:35:43+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 159" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="fetched first chunk of 19, total size is 9822409 bytes" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02: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" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=info msg="loaded track \"Rehab\" (paused: false, position: 1ms, duration: 213760ms, prefetched: false)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=trace msg="scheduling prefetch in 183s" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=trace msg="emitting websocket event: metadata" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="sending successful reply for dealer request" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="skipping dealer message" uri=playback-settings/content-settings-update Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","name":"Rehab","artist_names":["Amy Winehouse"],"album_name":"Back To Black","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","position":1,"duration":213760,"release_date":"year:2006 month:10 day:27","track_number":1,"disc_number":1}} Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","name":"Rehab","artist_names":["Amy Winehouse"],"album_name":"Back To Black","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","position":1,"duration":213760,"release_date":"year:2006 month:10 day:27","track_number":1,"disc_number":1}} Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=trace msg="emitting websocket event: playing" Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":false,"play_origin":"album"}} Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.682+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.683+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.683+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.683+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":false,"play_origin":"album"}} Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.696+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.697+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.697+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.698+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio go-librespot[32192]: time="2026-03-24T23:35:44+02:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.980+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.981+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.981+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:44.982+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:35:44 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:35:44 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:35:45 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:45.000+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:45 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:45.000+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:35:45 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:45.001+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:45 volumio volumio5-onboarding[1494]: time=2026-03-24T23:35:45.001+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:35:45 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:45 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:35:51 volumio go-librespot[32192]: time="2026-03-24T23:35:51+02:00" level=trace msg="sent dealer ping" Mar 24 23:35:51 volumio go-librespot[32192]: time="2026-03-24T23:35:51+02:00" level=trace msg="received dealer pong" Mar 24 23:35:53 volumio go-librespot[32192]: time="2026-03-24T23:35:53+02:00" level=debug msg="update volume requested to 65535/65535" Mar 24 23:35:54 volumio go-librespot[32192]: time="2026-03-24T23:35:54+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 24 23:35:54 volumio go-librespot[32192]: time="2026-03-24T23:35:54+02:00" level=trace msg="emitting websocket event: volume" Mar 24 23:35:54 volumio volumio[1306]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Mar 24 23:35:54 volumio volumio[1306]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Mar 24 23:35:54 volumio volumio[1306]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Mar 24 23:35:54 volumio volumio[1306]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Mar 24 23:35:55 volumio go-librespot[32192]: time="2026-03-24T23:35:55+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWTALrdBtcXjw" Mar 24 23:35:55 volumio go-librespot[32192]: time="2026-03-24T23:35:55+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Mar 24 23:35:55 volumio go-librespot[32192]: time="2026-03-24T23:35:55+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWWKeNBqaIy5U" Mar 24 23:35:55 volumio go-librespot[32192]: time="2026-03-24T23:35:55+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Mar 24 23:35:56 volumio go-librespot[32192]: time="2026-03-24T23:35:56+02:00" level=debug msg="handling set_sleep_timer player command from 0afb1dba3849c16d1ea3a4fe9fe5dc36a698fbbb" Mar 24 23:35:56 volumio go-librespot[32192]: time="2026-03-24T23:35:56+02:00" level=warning msg="failed handling dealer request" error="unsupported player command: set_sleep_timer" Mar 24 23:35:56 volumio go-librespot[32192]: time="2026-03-24T23:35:56+02:00" level=debug msg="handling update_context player command from 0afb1dba3849c16d1ea3a4fe9fe5dc36a698fbbb" Mar 24 23:35:57 volumio go-librespot[32192]: time="2026-03-24T23:35:57+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Mar 24 23:35:57 volumio go-librespot[32192]: time="2026-03-24T23:35:57+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:35:57 volumio go-librespot[32192]: time="2026-03-24T23:35:57+02:00" level=debug msg="sending successful reply for dealer request" Mar 24 23:35:57 volumio go-librespot[32192]: time="2026-03-24T23:35:57+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1EIf7w4nrKE2Gf" Mar 24 23:35:57 volumio go-librespot[32192]: time="2026-03-24T23:35:57+02:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:35:58 volumio go-librespot[32192]: time="2026-03-24T23:35:58+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX4xuWVBs4FgJ" Mar 24 23:35:58 volumio go-librespot[32192]: time="2026-03-24T23:35:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Mar 24 23:35:58 volumio go-librespot[32192]: time="2026-03-24T23:35:58+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DXbm6HfkbMtFZ" Mar 24 23:35:58 volumio go-librespot[32192]: time="2026-03-24T23:35:58+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Mar 24 23:36:08 volumio go-librespot[32192]: time="2026-03-24T23:36:08+02:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::volumioPause Mar 24 23:36:12 volumio volumio[1306]: info: CoreStateMachine::pause Mar 24 23:36:12 volumio volumio[1306]: info: CoreStateMachine::stPlaybackTimer Mar 24 23:36:12 volumio volumio[1306]: info: CoreStateMachine::servicePause Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::servicePause Mar 24 23:36:12 volumio volumio[1306]: info: Spotify Received pause Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: SPOTIFY PAUSE Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: {"status":"play","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","codec":"ogg","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Mar 24 23:36:12 volumio volumio[1306]: info: Sending Spotify command to local API: /player/pause Mar 24 23:36:12 volumio go-librespot[32192]: time="2026-03-24T23:36:12+02:00" level=debug msg="pause track at 27917ms" Mar 24 23:36:12 volumio go-librespot[32192]: time="2026-03-24T23:36:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:12 volumio go-librespot[32192]: time="2026-03-24T23:36:12+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:12 volumio go-librespot[32192]: time="2026-03-24T23:36:12+02:00" level=trace msg="emitting websocket event: paused" Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":27001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:12 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.641+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=27001 volume=100 Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.641+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=27001 volume=100 Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.642+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.642+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:12 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:12 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.651+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.651+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.652+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:12 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:12.652+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:12 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:18 volumio volumio[1306]: info: CoreCommandRouter::volumioVolatilePlay Mar 24 23:36:18 volumio volumio[1306]: info: CoreStateMachine::volatilePlay Mar 24 23:36:18 volumio volumio[1306]: info: Spotify Play Mar 24 23:36:18 volumio volumio[1306]: info: Sending Spotify command to local API: /player/resume Mar 24 23:36:18 volumio go-librespot[32192]: time="2026-03-24T23:36:18+02:00" level=trace msg="seek to 27917ms (diff: 177ms, samples: 1231139, bytes: 1181191)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:36:18 volumio go-librespot[32192]: time="2026-03-24T23:36:18+02: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" Mar 24 23:36:18 volumio go-librespot[32192]: time="2026-03-24T23:36:18+02:00" level=debug msg="resume track at 27740ms" Mar 24 23:36:19 volumio go-librespot[32192]: time="2026-03-24T23:36:19+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:19 volumio go-librespot[32192]: time="2026-03-24T23:36:19+02:00" level=trace msg="scheduling prefetch in 156s" Mar 24 23:36:19 volumio go-librespot[32192]: time="2026-03-24T23:36:19+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:19 volumio go-librespot[32192]: time="2026-03-24T23:36:19+02:00" level=trace msg="emitting websocket event: playing" Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":true,"play_origin":"album"}} Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":27001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.360+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=27001 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.360+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=27001 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.361+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.362+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":true,"play_origin":"album"}} Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.370+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.371+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.371+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":27001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.665+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=27001 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.666+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=27001 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.666+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.666+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:19 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.679+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.679+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.680+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:19.680+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:19 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::volumioPause Mar 24 23:36:20 volumio volumio[1306]: info: CoreStateMachine::pause Mar 24 23:36:20 volumio volumio[1306]: info: CoreStateMachine::stPlaybackTimer Mar 24 23:36:20 volumio volumio[1306]: info: CoreStateMachine::servicePause Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::servicePause Mar 24 23:36:20 volumio volumio[1306]: info: Spotify Received pause Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: SPOTIFY PAUSE Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: {"status":"play","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","codec":"ogg","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Mar 24 23:36:20 volumio volumio[1306]: info: Sending Spotify command to local API: /player/pause Mar 24 23:36:20 volumio go-librespot[32192]: time="2026-03-24T23:36:20+02:00" level=debug msg="pause track at 28872ms" Mar 24 23:36:20 volumio go-librespot[32192]: time="2026-03-24T23:36:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:20 volumio go-librespot[32192]: time="2026-03-24T23:36:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:20 volumio go-librespot[32192]: time="2026-03-24T23:36:20+02:00" level=trace msg="emitting websocket event: paused" Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":28001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:20 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.618+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=28001 volume=100 Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.618+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=28001 volume=100 Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.619+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.619+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:20 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:20 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.627+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.627+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.628+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:20 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:20.628+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:20 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:21 volumio go-librespot[32192]: time="2026-03-24T23:36:21+02:00" level=trace msg="sent dealer ping" Mar 24 23:36:21 volumio go-librespot[32192]: time="2026-03-24T23:36:21+02:00" level=trace msg="received dealer pong" Mar 24 23:36:21 volumio volumio[1306]: info: CoreCommandRouter::volumioVolatilePlay Mar 24 23:36:21 volumio volumio[1306]: info: CoreStateMachine::volatilePlay Mar 24 23:36:21 volumio volumio[1306]: info: Spotify Play Mar 24 23:36:21 volumio volumio[1306]: info: Sending Spotify command to local API: /player/resume Mar 24 23:36:21 volumio go-librespot[32192]: time="2026-03-24T23:36:21+02:00" level=trace msg="seek to 28872ms (diff: 91ms, samples: 1273255, bytes: 1224027)" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:36:21 volumio go-librespot[32192]: time="2026-03-24T23:36:21+02: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" Mar 24 23:36:21 volumio go-librespot[32192]: time="2026-03-24T23:36:21+02:00" level=debug msg="resume track at 28781ms" Mar 24 23:36:22 volumio go-librespot[32192]: time="2026-03-24T23:36:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:22 volumio go-librespot[32192]: time="2026-03-24T23:36:22+02:00" level=trace msg="scheduling prefetch in 155s" Mar 24 23:36:22 volumio go-librespot[32192]: time="2026-03-24T23:36:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:22 volumio go-librespot[32192]: time="2026-03-24T23:36:22+02:00" level=trace msg="emitting websocket event: playing" Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":true,"play_origin":"album"}} Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":28001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.216+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=28001 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.217+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=28001 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.217+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.217+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","resume":true,"play_origin":"album"}} Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.227+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.227+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.228+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.228+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":28001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.516+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=28001 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.517+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=28001 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.517+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.518+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: {"status":"play","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:22 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.528+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.528+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=1 volume=100 Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.528+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:22.529+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:22 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:30 volumio go-librespot[32192]: time="2026-03-24T23:36:30+02:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:1L5tZi0izXsi5Kk5OJf4W0" Mar 24 23:36:35 volumio volumio[1306]: info: CoreCommandRouter::volumioPause Mar 24 23:36:35 volumio volumio[1306]: info: CoreStateMachine::pause Mar 24 23:36:35 volumio volumio[1306]: info: CoreStateMachine::stPlaybackTimer Mar 24 23:36:35 volumio volumio[1306]: info: CoreStateMachine::servicePause Mar 24 23:36:35 volumio volumio[1306]: info: CoreCommandRouter::servicePause Mar 24 23:36:35 volumio volumio[1306]: info: Spotify Received pause Mar 24 23:36:35 volumio volumio[1306]: SPOTIFY: SPOTIFY PAUSE Mar 24 23:36:35 volumio volumio[1306]: SPOTIFY: {"status":"play","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","codec":"ogg","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Mar 24 23:36:35 volumio volumio[1306]: info: Sending Spotify command to local API: /player/pause Mar 24 23:36:35 volumio go-librespot[32192]: time="2026-03-24T23:36:35+02:00" level=debug msg="pause track at 42668ms" Mar 24 23:36:36 volumio go-librespot[32192]: time="2026-03-24T23:36:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:36 volumio go-librespot[32192]: time="2026-03-24T23:36:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 24 23:36:36 volumio go-librespot[32192]: time="2026-03-24T23:36:36+02:00" level=trace msg="emitting websocket event: paused" Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":41001,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:36 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.177+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=41001 volume=100 Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.177+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=41001 volume=100 Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.178+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.178+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:097eYvf9NKjFnv4xA9s2oV","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","play_origin":"album"}} Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: PUSH STATE SPOTIFY Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: {"status":"pause","service":"spop","title":"Rehab","artist":"Amy Winehouse","album":"Back To Black","albumart":"https://i.scdn.co/image/ab67616d00001e02dc65d5638a3de4a0bdf3c05f","uri":"spotify:track:1L5tZi0izXsi5Kk5OJf4W0","trackType":"spotify","seek":1,"duration":213,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:36 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:36 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.186+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.187+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=1 volume=100 Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.187+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:36 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:36.188+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=spotify:track:1L5tZi0izXsi5Kk5OJf4W0 title=Rehab Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:36 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:39 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:39.338+02:00 level=INFO msg="navigate to next page" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" latency=-192.409478ms timeout=10s from=APP_PAGE_ROOT to=APP_PAGE_LEGACY_DEVICE Mar 24 23:36:39 volumio sudo[32404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:36:39 volumio sudo[32404]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 23:36:39 volumio sudo[32404]: pam_unix(sudo:session): session closed for user root Mar 24 23:36:39 volumio sudo[32408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:36:39 volumio sudo[32408]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 23:36:39 volumio sudo[32408]: pam_unix(sudo:session): session closed for user root Mar 24 23:36:39 volumio volumio[1306]: verbose: New Socket.io Connection to 192.168.1.188 from 192.168.1.226 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:36:40 volumio sudo[32411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 24 23:36:40 volumio sudo[32411]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 23:36:40 volumio sudo[32411]: pam_unix(sudo:session): session closed for user root Mar 24 23:36:40 volumio sudo[32414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 24 23:36:40 volumio sudo[32414]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 24 23:36:40 volumio sudo[32414]: pam_unix(sudo:session): session closed for user root Mar 24 23:36:40 volumio volumio[1306]: verbose: New Socket.io Connection to 192.168.1.188 from 192.168.1.226 UA: Mozilla/5.0 (Linux; Android 16; SM-S938B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/146.0.7680.119 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::volumioGetVisibleSources Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 24 23:36:40 volumio volumio[1306]: info: Received Get System Info Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:36:40 volumio volumio[1306]: info: Discovery: Getting this device information Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:36:40 volumio volumio[1306]: info: Listing playlists Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 24 23:36:40 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:36:42 volumio volumio[1306]: info: Received Get System Info Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:36:42 volumio volumio[1306]: info: Discovery: Getting this device information Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 24 23:36:42 volumio volumio[1306]: info: Received Get System Info Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 24 23:36:42 volumio volumio[1306]: info: Discovery: Getting this device information Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::volumioGetState Mar 24 23:36:42 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 24 23:36:44 volumio volumio[1306]: info: Mar 24 23:36:44 volumio volumio[1306]: ---------------------------- MPD announces system playlist update Mar 24 23:36:44 volumio volumio[1306]: info: Ignoring MPD Status Update Mar 24 23:36:44 volumio volumio[1306]: info: Mar 24 23:36:44 volumio volumio[1306]: ---------------------------- MPD announces state update: player Mar 24 23:36:44 volumio volumio[1306]: info: ControllerMpd::getState Mar 24 23:36:44 volumio volumio[1306]: verbose: ControllerMpd::sendMpdCommand status Mar 24 23:36:44 volumio volumio[1306]: info: ------------------------------ 3ms Mar 24 23:36:44 volumio volumio[1306]: info: sendMpdCommand status took 2 milliseconds Mar 24 23:36:44 volumio volumio[1306]: verbose: ControllerMpd::parseState Mar 24 23:36:44 volumio volumio[1306]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 23:36:44 volumio volumio[1306]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 24 23:36:44 volumio volumio[1306]: verbose: ControllerMpd::parseTrackInfo Mar 24 23:36:44 volumio volumio[1306]: info: ControllerMpd::pushState Mar 24 23:36:44 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:44 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:44 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:44 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:44.117+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PLAYING positionMs=269203 volume=100 Mar 24 23:36:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:44.118+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PLAYING positionMs=269203 volume=100 Mar 24 23:36:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:44.118+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=http://streams.80s80s.de/100/mp3-192/volumio title="Sheena Easton - Sugar Walls" Mar 24 23:36:44 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:44.119+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=http://streams.80s80s.de/100/mp3-192/volumio title="Sheena Easton - Sugar Walls" Mar 24 23:36:44 volumio volumio[1306]: info: ------------------------------ 13ms Mar 24 23:36:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:44 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:47 volumio volumio[1306]: info: CoreCommandRouter::volumioPause Mar 24 23:36:47 volumio volumio[1306]: info: CoreStateMachine::pause Mar 24 23:36:47 volumio volumio[1306]: info: CoreStateMachine::stPlaybackTimer Mar 24 23:36:47 volumio volumio[1306]: info: CoreStateMachine::servicePause Mar 24 23:36:47 volumio volumio[1306]: info: CoreCommandRouter::servicePause Mar 24 23:36:47 volumio volumio[1306]: info: ControllerMpd::pause Mar 24 23:36:47 volumio volumio[1306]: verbose: ControllerMpd::sendMpdCommand pause Mar 24 23:36:47 volumio volumio[1306]: info: Mar 24 23:36:47 volumio volumio[1306]: ---------------------------- MPD announces state update: player Mar 24 23:36:47 volumio volumio[1306]: info: sendMpdCommand pause took 2 milliseconds Mar 24 23:36:47 volumio volumio[1306]: info: ControllerMpd::getState Mar 24 23:36:47 volumio volumio[1306]: verbose: ControllerMpd::sendMpdCommand status Mar 24 23:36:47 volumio volumio[1306]: info: sendMpdCommand status took 1 milliseconds Mar 24 23:36:47 volumio volumio[1306]: verbose: ControllerMpd::parseState Mar 24 23:36:47 volumio volumio[1306]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 23:36:47 volumio volumio[1306]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 24 23:36:47 volumio volumio[1306]: verbose: ControllerMpd::parseTrackInfo Mar 24 23:36:47 volumio volumio[1306]: info: ControllerMpd::pushState Mar 24 23:36:47 volumio volumio[1306]: info: CoreCommandRouter::servicePushState Mar 24 23:36:47 volumio volumio[1306]: info: CoreStateMachine::pushState Mar 24 23:36:47 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 23:36:47 volumio volumio[1306]: info: CoreCommandRouter::volumioPushState Mar 24 23:36:47 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:47.231+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" state=STATUS_PAUSED positionMs=272334 volume=100 Mar 24 23:36:47 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:47.231+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" state=STATUS_PAUSED positionMs=272334 volume=100 Mar 24 23:36:47 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:47.232+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%01,192.168.1.226:56518 @ 0x2cc0e40" id=http://streams.80s80s.de/100/mp3-192/volumio title="Sheena Easton - Sugar Walls" Mar 24 23:36:47 volumio volumio5-onboarding[1494]: time=2026-03-24T23:36:47.232+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.1.226:56518 @ 0x2cc1da0" id=http://streams.80s80s.de/100/mp3-192/volumio title="Sheena Easton - Sugar Walls" Mar 24 23:36:47 volumio volumio[1306]: info: ------------------------------ 11ms Mar 24 23:36:47 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:47 volumio volumio[1306]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mar 24 23:36:50 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Mar 24 23:36:51 volumio volumio[1306]: info: CoreCommandRouter::volumioGetQueue Mar 24 23:36:51 volumio volumio[1306]: info: CoreStateMachine::getQueue Mar 24 23:36:51 volumio volumio[1306]: info: CorePlayQueue::getQueue Mar 24 23:36:51 volumio go-librespot[32192]: time="2026-03-24T23:36:51+02:00" level=trace msg="sent dealer ping" Mar 24 23:36:51 volumio go-librespot[32192]: time="2026-03-24T23:36:51+02:00" level=trace msg="received dealer pong" Mar 24 23:36:53 volumio volumio[1306]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Mar 24 23:36:53 volumio volumio[1306]: info: In handleBrowseUri, curUri=spotify Mar 24 23:36:53 volumio volumio[1306]: info: Preload queue cleared Mar 24 23:36:53 volumio volumio[1306]: info: Preload queue cleared Mar 24 23:36:53 volumio volumio[1306]: info: Preload queue cleared Mar 24 23:36:53 volumio volumio[1306]: info: Preload queue cleared Mar 24 23:36:53 volumio volumio[1306]: info: [1774388213645] [80s80s] Pushing the next song state Prince - If I Was Your Girlfriend and getting next track. Mar 24 23:36:53 volumio volumio[1306]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 23:36:53 volumio volumio[1306]: TypeError: Cannot set property 'name' of undefined Mar 24 23:36:53 volumio volumio[1306]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Mar 24 23:36:53 volumio volumio[1306]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Mar 24 23:36:53 volumio volumio[1306]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Mar 24 23:36:53 volumio volumio[1306]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Mar 24 23:36:53 volumio volumio[1306]: at processImmediate (internal/timers.js:461:21) Mar 24 23:36:53 volumio volumio[1306]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 23:36:54 volumio sudo[32439]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-24 23:35 Mar 24 23:36:54 volumio sudo[32439]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"