-- Logs begin at Fri 2025-07-11 07:13:18 CEST, end at Fri 2025-07-11 11:48:34 CEST. -- Jul 11 11:47:03 qs-radio go-librespot[8178]: time="2025-07-11T11:47:03+02:00" level=debug msg="fetched chunk 8/12, size: 524288" uri="spotify:track:21VnSlwtvNKUFFHHKqt7fI" Jul 11 11:47:12 qs-radio go-librespot[8178]: time="2025-07-11T11:47:12+02:00" level=trace msg="sent dealer ping" Jul 11 11:47:12 qs-radio go-librespot[8178]: time="2025-07-11T11:47:12+02:00" level=trace msg="received dealer pong" Jul 11 11:47:14 qs-radio volumio[7895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 11 11:47:14 qs-radio volumio[7895]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 11 11:47:15 qs-radio volumio[7895]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 11 11:47:16 qs-radio go-librespot[8178]: time="2025-07-11T11:47:16+02:00" level=debug msg="fetched chunk 9/12, size: 524288" uri="spotify:track:21VnSlwtvNKUFFHHKqt7fI" Jul 11 11:47:29 qs-radio go-librespot[8178]: time="2025-07-11T11:47:29+02:00" level=debug msg="fetched chunk 10/12, size: 524288" uri="spotify:track:21VnSlwtvNKUFFHHKqt7fI" Jul 11 11:47:42 qs-radio go-librespot[8178]: time="2025-07-11T11:47:42+02:00" level=debug msg="fetched chunk 11/12, size: 524288" uri="spotify:track:21VnSlwtvNKUFFHHKqt7fI" Jul 11 11:47:42 qs-radio go-librespot[8178]: time="2025-07-11T11:47:42+02:00" level=trace msg="received accesspoint ping" Jul 11 11:47:42 qs-radio go-librespot[8178]: time="2025-07-11T11:47:42+02:00" level=trace msg="received accesspoint pong ack" Jul 11 11:47:42 qs-radio go-librespot[8178]: time="2025-07-11T11:47:42+02:00" level=trace msg="sent dealer ping" Jul 11 11:47:42 qs-radio go-librespot[8178]: time="2025-07-11T11:47:42+02:00" level=trace msg="received dealer pong" Jul 11 11:47:55 qs-radio go-librespot[8178]: time="2025-07-11T11:47:55+02:00" level=debug msg="fetched chunk 12/12, size: 32496" uri="spotify:track:21VnSlwtvNKUFFHHKqt7fI" Jul 11 11:48:05 qs-radio go-librespot[8178]: time="2025-07-11T11:48:05+02:00" level=debug msg="prefetching next track" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:05 qs-radio go-librespot[8178]: time="2025-07-11T11:48:05+02:00" level=debug msg="selected format OGG_VORBIS_320 (9de24d5fadb5327bd9c1c1cdd72afb6015f5e445)" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:05 qs-radio go-librespot[8178]: time="2025-07-11T11:48:05+02:00" level=debug msg="requested aes key for file 9de24d5fadb5327bd9c1c1cdd72afb6015f5e445, gid: 0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:05 qs-radio go-librespot[8178]: time="2025-07-11T11:48:05+02:00" level=debug msg="fetched first chunk of 13, total size is 6479925 bytes" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:05 qs-radio go-librespot[8178]: time="2025-07-11T11:48:05+02:00" level=info msg="prefetched track \"Help Me Lose My Mind\" (duration: 172945ms)" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:06 qs-radio go-librespot[8178]: time="2025-07-11T11:48:06+02:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:06 qs-radio go-librespot[8178]: time="2025-07-11T11:48:06+02:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:06 qs-radio go-librespot[8178]: time="2025-07-11T11:48:06+02:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:12 qs-radio go-librespot[8178]: time="2025-07-11T11:48:12+02:00" level=trace msg="sent dealer ping" Jul 11 11:48:12 qs-radio go-librespot[8178]: time="2025-07-11T11:48:12+02:00" level=trace msg="received dealer pong" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=trace msg="emitting websocket event: not_playing" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:21VnSlwtvNKUFFHHKqt7fI","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: error: Failed to decode event: not_playing Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:21VnSlwtvNKUFFHHKqt7fI","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: error: Failed to decode event: not_playing Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:21VnSlwtvNKUFFHHKqt7fI","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: error: Failed to decode event: not_playing Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=trace msg="emitting websocket event: will_play" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=info msg="loaded track \"Help Me Lose My Mind\" (paused: false, position: 0ms, duration: 172945ms, prefetched: true)" uri="spotify:track:0yKlFaSKtA5wdF8pWgyoo1" Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=trace msg="scheduling prefetch in 143s" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=trace msg="emitting websocket event: metadata" Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","name":"Help Me Lose My Mind","artist_names":["Gravagerz"],"album_name":"Help Me Lose My Mind","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02755106153bca6032411ee87d","position":0,"duration":172945,"release_date":"year:2024 month:11 day:15","track_number":1,"disc_number":1}} Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","name":"Help Me Lose My Mind","artist_names":["Gravagerz"],"album_name":"Help Me Lose My Mind","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02755106153bca6032411ee87d","position":0,"duration":172945,"release_date":"year:2024 month:11 day:15","track_number":1,"disc_number":1}} Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","name":"Help Me Lose My Mind","artist_names":["Gravagerz"],"album_name":"Help Me Lose My Mind","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02755106153bca6032411ee87d","position":0,"duration":172945,"release_date":"year:2024 month:11 day:15","track_number":1,"disc_number":1}} Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jul 11 11:48:34 qs-radio go-librespot[8178]: time="2025-07-11T11:48:34+02:00" level=trace msg="emitting websocket event: playing" Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","play_origin":"playlist"}} Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: PUSH STATE SPOTIFY Jul 11 11:48:34 qs-radio volumio[7895]: SPOTIFY: {"status":"play","service":"spop","title":"Help Me Lose My Mind","artist":"Gravagerz","album":"Help Me Lose My Mind","albumart":"https://i.scdn.co/image/ab67616d00001e02755106153bca6032411ee87d","uri":"spotify:track:0yKlFaSKtA5wdF8pWgyoo1","trackType":"spotify","seek":0,"duration":172,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jul 11 11:48:34 qs-radio volumio[7895]: info: CoreCommandRouter::servicePushState Jul 11 11:48:34 qs-radio volumio[7895]: info: CoreStateMachine::pushState Jul 11 11:48:34 qs-radio volumio[7895]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 11 11:48:34 qs-radio volumio[7895]: info: CoreCommandRouter::volumioPushState Jul 11 11:48:34 qs-radio volumio[7895]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 11:48:34 qs-radio volumio[7895]: TypeError: Cannot read property 'pushState' of null Jul 11 11:48:34 qs-radio volumio[7895]: at /volumio/app/index.js:326:32 Jul 11 11:48:34 qs-radio volumio[7895]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Jul 11 11:48:34 qs-radio volumio[7895]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Jul 11 11:48:34 qs-radio volumio[7895]: at CoreCommandRouter.volumioPushState (/volumio/app/index.js:324:13) Jul 11 11:48:34 qs-radio volumio[7895]: at CoreStateMachine.pushState (/volumio/app/statemachine.js:532:22) Jul 11 11:48:34 qs-radio volumio[7895]: at CoreStateMachine.syncState (/volumio/app/statemachine.js:593:10) Jul 11 11:48:34 qs-radio volumio[7895]: at CoreCommandRouter.servicePushState (/volumio/app/index.js:414:28) Jul 11 11:48:34 qs-radio volumio[7895]: at ControllerSpotify.pushState (/data/plugins/music_service/spop/index.js:433:31) Jul 11 11:48:34 qs-radio volumio[7895]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:323:14) Jul 11 11:48:34 qs-radio volumio[7895]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Jul 11 11:48:34 qs-radio volumio[7895]: at WebSocket.emit (events.js:400:28) Jul 11 11:48:34 qs-radio volumio[7895]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jul 11 11:48:34 qs-radio volumio[7895]: at Receiver.emit (events.js:400:28) Jul 11 11:48:34 qs-radio volumio[7895]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jul 11 11:48:34 qs-radio volumio[7895]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jul 11 11:48:34 qs-radio volumio[7895]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jul 11 11:48:34 qs-radio volumio[7895]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 11 11:48:34 qs-radio sudo[16567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-11 11:47 Jul 11 11:48:34 qs-radio sudo[16567]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:41:06 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="097e6b8b481766e7a0f9527e4a34a29b"