-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Fri 2025-10-17 21:20:13 CEST. -- Oct 17 21:19:05 volumio go-librespot[1221]: time="2025-10-17T21:19:05+02:00" level=trace msg="sent dealer ping" Oct 17 21:19:05 volumio go-librespot[1221]: time="2025-10-17T21:19:05+02:00" level=trace msg="received dealer pong" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="dealer connection closed" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="dealer recv loop stopped" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="obtained new client token: AAAP+xReawPUI0nXZakH+yHWxKkugHZtR/UzYYWbSkg/dZK7RmJBdRQzkw/E1eMkXzQpEOfahqRnfKsPDGsbK7z3ouLersSySdD/e9eB7LGWl3XnMhfWkDa+GSjufyKYwCDBpM4VPjNAH8PVtlg2aaggsq96nBNMgxz8O3PVKAZEXoOAe69pMsSUV9VDgZGvMyMHLSAd4q1k+Nmf8nWG3KWsLI1ox6VuyWmQoHV1DknpAwqyqPYPuhc=" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="completed keyexchange" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="completed challenge" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=info msg="authenticated AP" username="vz*********************ic" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=info msg="authenticated Login5" username="vz*********************ic" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=info msg="accepted zeroconf from iPhone" username="vz*********************ic" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="dealer connection opened" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="starting accesspoint recv loop" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="starting dealer recv loop" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="received accesspoint ping" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="received connection id: Yjk3MDYzMTItNzYz...NzA3RkNDRkM0MQ==" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="received accesspoint pong ack" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="handling play player command from 8b23874e74253ded7dae75267d0daef818e96925" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="resolved context of track" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="fetched new page 0 with 117 items (list: 117)" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="emitting websocket event: will_play" Oct 17 21:19:19 volumio volumio[1040]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="selected format OGG_VORBIS_320 (72635f649d76dfec66654b7043e72248842e567c)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=debug msg="requested aes key for file 72635f649d76dfec66654b7043e72248842e567c, gid: 6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:19 volumio go-librespot[1221]: time="2025-10-17T21:19:19+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="fetched first chunk of 12, total size is 5887896 bytes" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="created new output device" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=info msg="loaded track \"Big Jet Plane\" (paused: true, position: 0ms, duration: 150000ms, prefetched: false)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=trace msg="emitting websocket event: metadata" Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","name":"Big Jet Plane","artist_names":["Restricted"],"album_name":"Big Jet Plane","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","position":0,"duration":150000,"release_date":"year:2022 month:12 day:9","track_number":1,"disc_number":1}} Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="sending successful reply for dealer request" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=trace msg="emitting websocket event: paused" Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:20 volumio volumio[1040]: info: Spotify is playing in volatile mode Oct 17 21:19:20 volumio volumio[1040]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: UNSET VOLATILE Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: {"status":"play","position":0,"title":"Koto - Visitors","artist":"80s80s Italo Disco","album":"","albumart":"https://is3-ssl.mzstatic.com/image/thumb/Music/v4/2f/af/0f/2faf0fba-5985-3b3e-fb34-0eb5c31e39f8/source/600x600bb.jpg","uri":"http://streams.80s80s.de/italohits/mp3-192/volumio","trackType":"80s80s Radio","seek":0,"duration":"204","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":90,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Oct 17 21:19:20 volumio volumio[1040]: info: Setting Spotify stop after unset volatile call Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: PUSH STATE SPOTIFY Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: {"status":"pause","service":"spop","title":"Big Jet Plane","artist":"Restricted","album":"Big Jet Plane","albumart":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","trackType":"spotify","seek":0,"duration":150,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 17 21:19:20 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 17 21:19:20 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 17 21:19:20 volumio volumio[1040]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 17 21:19:20 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 17 21:19:20 volumio go-librespot[1221]: time="2025-10-17T21:19:20+02:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:20 volumio volumio[1040]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 17 21:19:20 volumio volumio[1040]: info: CoreCommandRouter::volumioGetState Oct 17 21:19:20 volumio volumio[1040]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0 Oct 17 21:19:20 volumio volumio[1040]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 17 21:19:20 volumio volumio[1040]: info: Spotify Stop Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: SPOTIFY STOP Oct 17 21:19:20 volumio volumio[1040]: SPOTIFY: {"status":"pause","title":"Big Jet Plane","artist":"Restricted","album":"Big Jet Plane","albumart":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","trackType":"spotify","codec":"ogg","seek":0,"duration":150,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":90,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="handling play player command from 8b23874e74253ded7dae75267d0daef818e96925" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="resolved context of track" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=trace msg="fetched new page 0 with 117 items (list: 117)" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=trace msg="emitting websocket event: will_play" Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="selected format OGG_VORBIS_320 (72635f649d76dfec66654b7043e72248842e567c)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="requested aes key for file 72635f649d76dfec66654b7043e72248842e567c, gid: 6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="fetched first chunk of 12, total size is 5887896 bytes" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=info msg="loaded track \"Big Jet Plane\" (paused: true, position: 0ms, duration: 150000ms, prefetched: false)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=trace msg="emitting websocket event: metadata" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="sending successful reply for dealer request" Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","name":"Big Jet Plane","artist_names":["Restricted"],"album_name":"Big Jet Plane","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","position":0,"duration":150000,"release_date":"year:2022 month:12 day:9","track_number":1,"disc_number":1}} Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:33 volumio go-librespot[1221]: time="2025-10-17T21:19:33+02:00" level=trace msg="emitting websocket event: paused" Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: PUSH STATE SPOTIFY Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: {"status":"pause","service":"spop","title":"Big Jet Plane","artist":"Restricted","album":"Big Jet Plane","albumart":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","trackType":"spotify","seek":0,"duration":150,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 17 21:19:33 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 17 21:19:33 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 17 21:19:33 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 17 21:19:33 volumio volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 17 21:19:49 volumio go-librespot[1221]: time="2025-10-17T21:19:49+02:00" level=trace msg="sent dealer ping" Oct 17 21:19:49 volumio go-librespot[1221]: time="2025-10-17T21:19:49+02:00" level=trace msg="received dealer pong" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="handling play player command from 8b23874e74253ded7dae75267d0daef818e96925" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="resolved context of track" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=trace msg="fetched new page 0 with 117 items (list: 117)" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=trace msg="emitting websocket event: will_play" Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="selected format OGG_VORBIS_320 (72635f649d76dfec66654b7043e72248842e567c)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="requested aes key for file 72635f649d76dfec66654b7043e72248842e567c, gid: 6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="fetched first chunk of 12, total size is 5887896 bytes" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=info msg="loaded track \"Big Jet Plane\" (paused: true, position: 0ms, duration: 150000ms, prefetched: false)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=trace msg="emitting websocket event: metadata" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="sending successful reply for dealer request" Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","name":"Big Jet Plane","artist_names":["Restricted"],"album_name":"Big Jet Plane","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","position":0,"duration":150000,"release_date":"year:2022 month:12 day:9","track_number":1,"disc_number":1}} Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=trace msg="emitting websocket event: paused" Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: PUSH STATE SPOTIFY Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: {"status":"pause","service":"spop","title":"Big Jet Plane","artist":"Restricted","album":"Big Jet Plane","albumart":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","trackType":"spotify","seek":0,"duration":150,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 17 21:19:50 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 17 21:19:50 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 17 21:19:50 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 17 21:19:50 volumio volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 17 21:19:50 volumio go-librespot[1221]: time="2025-10-17T21:19:50+02:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:19:57 volumio go-librespot[1221]: time="2025-10-17T21:19:57+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Oct 17 21:19:57 volumio go-librespot[1221]: time="2025-10-17T21:19:57+02:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1EVJHK7Q1TBABQ" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="handling play player command from 8b23874e74253ded7dae75267d0daef818e96925" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="resolved context of track" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=trace msg="fetched new page 0 with 117 items (list: 117)" uri="spotify:user:vzgp1rdl50yc18c30vl5t4nic:collection" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="loading track (paused: true, position: 0ms)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=trace msg="emitting websocket event: will_play" Oct 17 21:20:03 volumio volumio[1040]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="selected format OGG_VORBIS_320 (72635f649d76dfec66654b7043e72248842e567c)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=debug msg="requested aes key for file 72635f649d76dfec66654b7043e72248842e567c, gid: 6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:03 volumio go-librespot[1221]: time="2025-10-17T21:20:03+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="fetched first chunk of 12, total size is 5887896 bytes" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=info msg="loaded track \"Big Jet Plane\" (paused: true, position: 0ms, duration: 150000ms, prefetched: false)" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=trace msg="emitting websocket event: metadata" Oct 17 21:20:04 volumio volumio[1040]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","name":"Big Jet Plane","artist_names":["Restricted"],"album_name":"Big Jet Plane","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","position":0,"duration":150000,"release_date":"year:2022 month:12 day:9","track_number":1,"disc_number":1}} Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="sending successful reply for dealer request" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=trace msg="emitting websocket event: paused" Oct 17 21:20:04 volumio volumio[1040]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","play_origin":"connect"}} Oct 17 21:20:04 volumio volumio[1040]: SPOTIFY: PUSH STATE SPOTIFY Oct 17 21:20:04 volumio volumio[1040]: SPOTIFY: {"status":"pause","service":"spop","title":"Big Jet Plane","artist":"Restricted","album":"Big Jet Plane","albumart":"https://i.scdn.co/image/ab67616d00001e0205da2b226cda948badddbf2e","uri":"spotify:track:6nYJWAPKIJfXIKtiYc4P4O","trackType":"spotify","seek":0,"duration":150,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 17 21:20:04 volumio volumio[1040]: info: CoreCommandRouter::servicePushState Oct 17 21:20:04 volumio volumio[1040]: info: CoreStateMachine::pushState Oct 17 21:20:04 volumio volumio[1040]: info: CoreCommandRouter::volumioPushState Oct 17 21:20:04 volumio volumio[1040]: SPOTIFY: RECEIVED VOLUMIO VOLUME 90 Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:04 volumio go-librespot[1221]: time="2025-10-17T21:20:04+02:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:6nYJWAPKIJfXIKtiYc4P4O" Oct 17 21:20:12 volumio volumio[1040]: info: [1760728812551] [80s80s] Pushing the next song state Gillian Lane - Take My Heart Away and getting next track. Oct 17 21:20:12 volumio volumio[1040]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 21:20:12 volumio volumio[1040]: TypeError: Cannot set property 'name' of undefined Oct 17 21:20:12 volumio volumio[1040]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Oct 17 21:20:12 volumio volumio[1040]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Oct 17 21:20:12 volumio volumio[1040]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Oct 17 21:20:12 volumio volumio[1040]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Oct 17 21:20:12 volumio volumio[1040]: at processImmediate (internal/timers.js:461:21) Oct 17 21:20:12 volumio volumio[1040]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 17 21:20:13 volumio sudo[30758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-17 21:19 Oct 17 21:20:13 volumio sudo[30758]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"