-- Logs begin at Mon 2026-02-02 22:39:26 CET, end at Fri 2026-02-06 21:22:16 CET. -- Feb 06 21:21:05 volumio go-librespot[1301]: time="2026-02-06T21:21:05+01:00" level=debug msg="fetched chunk 7/17, size: 524288" uri="spotify:track:1vI7Ggo98A3NyHHoI9mHOB" Feb 06 21:21:18 volumio go-librespot[1301]: time="2026-02-06T21:21:18+01:00" level=debug msg="fetched chunk 8/17, size: 524288" uri="spotify:track:1vI7Ggo98A3NyHHoI9mHOB" Feb 06 21:21:25 volumio go-librespot[1301]: time="2026-02-06T21:21:25+01:00" level=trace msg="sent dealer ping" Feb 06 21:21:25 volumio go-librespot[1301]: time="2026-02-06T21:21:25+01:00" level=trace msg="received dealer pong" Feb 06 21:21:30 volumio go-librespot[1301]: time="2026-02-06T21:21:30+01:00" level=debug msg="fetched chunk 9/17, size: 524288" uri="spotify:track:1vI7Ggo98A3NyHHoI9mHOB" Feb 06 21:21:43 volumio go-librespot[1301]: time="2026-02-06T21:21:43+01:00" level=trace msg="received accesspoint ping" Feb 06 21:21:43 volumio go-librespot[1301]: time="2026-02-06T21:21:43+01:00" level=trace msg="received accesspoint pong ack" Feb 06 21:21:43 volumio go-librespot[1301]: time="2026-02-06T21:21:43+01:00" level=debug msg="fetched chunk 10/17, size: 524288" uri="spotify:track:1vI7Ggo98A3NyHHoI9mHOB" Feb 06 21:21:55 volumio go-librespot[1301]: time="2026-02-06T21:21:55+01:00" level=trace msg="sent dealer ping" Feb 06 21:21:55 volumio go-librespot[1301]: time="2026-02-06T21:21:55+01:00" level=trace msg="received dealer pong" Feb 06 21:21:56 volumio go-librespot[1301]: time="2026-02-06T21:21:56+01:00" level=debug msg="fetched chunk 11/17, size: 524288" uri="spotify:track:1vI7Ggo98A3NyHHoI9mHOB" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=debug msg="handling pause player command from ebdf2140f5811e6887119cded593b9cec3f4fcce" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=debug msg="pause track at 107223ms" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=debug msg="sending successful reply for dealer request" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:03 volumio go-librespot[1301]: time="2026-02-06T21:22:03+01:00" level=trace msg="emitting websocket event: paused" Feb 06 21:22:03 volumio volumio[991]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:station:album:6SfnjkSphtKowg3tt7azDi","uri":"spotify:track:1vI7Ggo98A3NyHHoI9mHOB","play_origin":""}} Feb 06 21:22:03 volumio volumio[991]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 21:22:03 volumio volumio[991]: SPOTIFY: {"status":"pause","service":"spop","title":"In the End","artist":"Shiner","album":"Schadenfreude","albumart":"https://i.scdn.co/image/ab67616d00001e022f07768863a04efdfececc76","uri":"spotify:track:1vI7Ggo98A3NyHHoI9mHOB","trackType":"spotify","seek":107000,"duration":230,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 06 21:22:03 volumio volumio[991]: info: CoreCommandRouter::servicePushState Feb 06 21:22:03 volumio volumio[991]: info: CoreStateMachine::pushState Feb 06 21:22:03 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 21:22:03 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Feb 06 21:22:03 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="handling play player command from ebdf2140f5811e6887119cded593b9cec3f4fcce" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="resolved context of track" uri="spotify:album:6SfnjkSphtKowg3tt7azDi" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=trace msg="fetched new page 0 with 8 items (list: 8)" uri="spotify:album:6SfnjkSphtKowg3tt7azDi" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=trace msg="emitting websocket event: will_play" Feb 06 21:22:05 volumio volumio[991]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:6SfnjkSphtKowg3tt7azDi","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","play_origin":""}} Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="selected format OGG_VORBIS_320 (809e31333d1fd1b4ccb4d6d0f2cf613078f8efdb)" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=debug msg="requested aes key for file 809e31333d1fd1b4ccb4d6d0f2cf613078f8efdb, gid: 4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:05 volumio go-librespot[1301]: time="2026-02-06T21:22:05+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="fetched first chunk of 24, total size is 12312464 bytes" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames, PCM format = FLOAT_LE" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=info msg="loaded track \"Waves\" (paused: false, position: 1ms, duration: 330719ms, prefetched: false)" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="fetched chunk 2/23, size: 524288" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=trace msg="scheduling prefetch in 300s" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=trace msg="emitting websocket event: metadata" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="sending successful reply for dealer request" Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","name":"Waves","artist_names":["Hum"],"album_name":"Inlet","album_cover_url":"https://i.scdn.co/image/ab67616d00001e024eee010f3e0f5b194d519cbc","position":1,"duration":330719,"release_date":"year:2020 month:6 day:24","track_number":1,"disc_number":1}} Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="fetched chunk 1/23, size: 524288" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=trace msg="emitting websocket event: playing" Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:6SfnjkSphtKowg3tt7azDi","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","resume":false,"play_origin":""}} Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"Waves","artist":"Hum","album":"Inlet","albumart":"https://i.scdn.co/image/ab67616d00001e024eee010f3e0f5b194d519cbc","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","trackType":"spotify","seek":1,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 06 21:22:06 volumio volumio[991]: info: CoreCommandRouter::servicePushState Feb 06 21:22:06 volumio volumio[991]: info: CoreStateMachine::pushState Feb 06 21:22:06 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 21:22:06 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Feb 06 21:22:06 volumio go-librespot[1301]: time="2026-02-06T21:22:06+01:00" level=debug msg="fetched chunk 3/23, size: 524288" uri="spotify:track:4ciwo5ZCsyzCPjymj940Fw" Feb 06 21:22:06 volumio volumio[991]: info: [LastFM] Current track has sufficient metadata: title (Waves) and artist (Hum) passed on explicitly Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: {"status":"play","service":"spop","title":"Waves","artist":"Hum","album":"Inlet","albumart":"https://i.scdn.co/image/ab67616d00001e024eee010f3e0f5b194d519cbc","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","trackType":"spotify","seek":1,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 06 21:22:06 volumio volumio[991]: info: CoreCommandRouter::servicePushState Feb 06 21:22:06 volumio volumio[991]: info: CoreStateMachine::pushState Feb 06 21:22:06 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Feb 06 21:22:06 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 06 21:22:09 volumio go-librespot[1301]: time="2026-02-06T21:22:09+01:00" level=debug msg="handling pause player command from ebdf2140f5811e6887119cded593b9cec3f4fcce" Feb 06 21:22:09 volumio go-librespot[1301]: time="2026-02-06T21:22:09+01:00" level=debug msg="pause track at 3896ms" Feb 06 21:22:10 volumio go-librespot[1301]: time="2026-02-06T21:22:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:10 volumio go-librespot[1301]: time="2026-02-06T21:22:10+01:00" level=debug msg="sending successful reply for dealer request" Feb 06 21:22:10 volumio go-librespot[1301]: time="2026-02-06T21:22:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 21:22:10 volumio go-librespot[1301]: time="2026-02-06T21:22:10+01:00" level=trace msg="emitting websocket event: paused" Feb 06 21:22:10 volumio volumio[991]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:album:6SfnjkSphtKowg3tt7azDi","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","play_origin":""}} Feb 06 21:22:10 volumio volumio[991]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 21:22:10 volumio volumio[991]: SPOTIFY: {"status":"pause","service":"spop","title":"Waves","artist":"Hum","album":"Inlet","albumart":"https://i.scdn.co/image/ab67616d00001e024eee010f3e0f5b194d519cbc","uri":"spotify:track:4ciwo5ZCsyzCPjymj940Fw","trackType":"spotify","seek":3001,"duration":330,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 06 21:22:10 volumio volumio[991]: info: CoreCommandRouter::servicePushState Feb 06 21:22:10 volumio volumio[991]: info: CoreStateMachine::pushState Feb 06 21:22:10 volumio volumio[991]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 21:22:10 volumio volumio[991]: info: CoreCommandRouter::volumioPushState Feb 06 21:22:10 volumio volumio[991]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Feb 06 21:22:15 volumio volumio[991]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 21:22:15 volumio volumio[991]: TypeError: Cannot read property '@' of undefined Feb 06 21:22:15 volumio volumio[991]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Feb 06 21:22:15 volumio volumio[991]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Feb 06 21:22:15 volumio volumio[991]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Feb 06 21:22:15 volumio volumio[991]: at Parser.emit (events.js:315:20) Feb 06 21:22:15 volumio volumio[991]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Feb 06 21:22:15 volumio volumio[991]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Feb 06 21:22:15 volumio volumio[991]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Feb 06 21:22:15 volumio volumio[991]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Feb 06 21:22:15 volumio volumio[991]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Feb 06 21:22:15 volumio volumio[991]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Feb 06 21:22:15 volumio volumio[991]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Feb 06 21:22:15 volumio volumio[991]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Feb 06 21:22:15 volumio volumio[991]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Feb 06 21:22:15 volumio volumio[991]: at IncomingMessage.emit (events.js:327:22) Feb 06 21:22:15 volumio volumio[991]: at endReadableNT (internal/streams/readable.js:1327:12) Feb 06 21:22:15 volumio volumio[991]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Feb 06 21:22:15 volumio volumio[991]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 21:22:16 volumio sudo[31210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-06 21:21 Feb 06 21:22:16 volumio sudo[31210]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"