-- Logs begin at Tue 2025-05-13 18:48:13 CEST, end at Tue 2025-05-13 22:44:10 CEST. -- Mai 13 22:43:03 volumio go-librespot[9592]: time="2025-05-13T22:43:03+02:00" level=debug msg="handling play player command from c8c1eecc94d2a00e6c63b0dce789b5557b3aa57e" Mai 13 22:43:03 volumio go-librespot[9592]: time="2025-05-13T22:43:03+02:00" level=debug msg="resolved context of track" uri="spotify:album:2CIcEol2CvDIMp4rmlsxfc" Mai 13 22:43:03 volumio go-librespot[9592]: time="2025-05-13T22:43:03+02:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:album:2CIcEol2CvDIMp4rmlsxfc" Mai 13 22:43:03 volumio go-librespot[9592]: time="2025-05-13T22:43:03+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=trace msg="emitting websocket event: will_play" Mai 13 22:43:04 volumio volumio[9347]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","play_origin":"playlist"}} Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="selected format OGG_VORBIS_320 (794ebc116bc38c8e7f66e164c40de612a4c81a27)" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="requested aes key for file 794ebc116bc38c8e7f66e164c40de612a4c81a27, gid: 1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="fetched first chunk of 29, total size is 14686040 bytes" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=info msg="loaded track \"Hans\" (paused: false, position: 0ms, duration: 350520ms, prefetched: false)" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="fetched chunk 1/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=trace msg="scheduling prefetch in 320s" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=trace msg="emitting websocket event: metadata" Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="sending successful reply for dealer request" Mai 13 22:43:04 volumio volumio[9347]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","name":"Hans","artist_names":["Widersacher aller Liedermacher"],"album_name":"Die Bris","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026df3c94a8dc689ff4a8722f4","position":0,"duration":350520,"release_date":"year:2020 month:11 day:22","track_number":8,"disc_number":1}} Mai 13 22:43:04 volumio go-librespot[9592]: time="2025-05-13T22:43:04+02:00" level=debug msg="fetched chunk 3/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:05 volumio go-librespot[9592]: time="2025-05-13T22:43:05+02:00" level=debug msg="fetched chunk 2/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:05 volumio go-librespot[9592]: time="2025-05-13T22:43:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mai 13 22:43:05 volumio go-librespot[9592]: time="2025-05-13T22:43:05+02:00" level=trace msg="emitting websocket event: playing" Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","play_origin":"playlist"}} Mai 13 22:43:05 volumio volumio[9347]: info: Spotify is playing in volatile mode Mai 13 22:43:05 volumio volumio[9347]: info: CoreStateMachine::setConsumeUpdateService undefined Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: UNSET VOLATILE Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: {"status":"play","position":13,"title":"Don't Be Late - Live","artist":"Saga","album":"So Good so Far - Live at Rock of Ages","albumart":"https://i.scdn.co/image/ab67616d0000b273899327bc75ce394757361e4c","uri":"spotify:track:1lsy9QdhMpTIMUqU2XGT6a","trackType":"spotify","codec":"ogg","seek":251,"duration":527,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Mai 13 22:43:05 volumio volumio[9347]: info: Setting Spotify stop after unset volatile call Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: PUSH STATE SPOTIFY Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: {"status":"play","service":"spop","title":"Hans","artist":"Widersacher aller Liedermacher","album":"Die Bris","albumart":"https://i.scdn.co/image/ab67616d00001e026df3c94a8dc689ff4a8722f4","uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","trackType":"spotify","seek":0,"duration":350,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Mai 13 22:43:05 volumio volumio[9347]: info: CoreCommandRouter::servicePushState Mai 13 22:43:05 volumio volumio[9347]: info: CoreStateMachine::pushState Mai 13 22:43:05 volumio volumio[9347]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mai 13 22:43:05 volumio volumio[9347]: info: CoreCommandRouter::volumioPushState Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: PUSH STATE SPOTIFY Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: {"status":"play","service":"spop","title":"Hans","artist":"Widersacher aller Liedermacher","album":"Die Bris","albumart":"https://i.scdn.co/image/ab67616d00001e026df3c94a8dc689ff4a8722f4","uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","trackType":"spotify","seek":0,"duration":350,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Mai 13 22:43:05 volumio volumio[9347]: info: CoreCommandRouter::servicePushState Mai 13 22:43:05 volumio volumio[9347]: info: CoreStateMachine::pushState Mai 13 22:43:05 volumio volumio[9347]: info: CoreCommandRouter::volumioPushState Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Mai 13 22:43:05 volumio volumio[9347]: info: Spotify Stop Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: SPOTIFY STOP Mai 13 22:43:05 volumio volumio[9347]: SPOTIFY: {"status":"play","title":"Hans","artist":"Widersacher aller Liedermacher","album":"Die Bris","albumart":"https://i.scdn.co/image/ab67616d00001e026df3c94a8dc689ff4a8722f4","uri":"spotify:track:1FeoJDSHts21OhuWDZoHeZ","trackType":"spotify","codec":"ogg","seek":0,"duration":350,"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"} Mai 13 22:43:17 volumio go-librespot[9592]: time="2025-05-13T22:43:17+02:00" level=debug msg="fetched chunk 4/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:28 volumio go-librespot[9592]: time="2025-05-13T22:43:28+02:00" level=trace msg="sent dealer ping" Mai 13 22:43:28 volumio go-librespot[9592]: time="2025-05-13T22:43:28+02:00" level=trace msg="received dealer pong" Mai 13 22:43:30 volumio go-librespot[9592]: time="2025-05-13T22:43:30+02:00" level=debug msg="fetched chunk 5/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:43 volumio go-librespot[9592]: time="2025-05-13T22:43:43+02:00" level=debug msg="fetched chunk 6/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:50 volumio go-librespot[9592]: time="2025-05-13T22:43:50+02:00" level=trace msg="received accesspoint ping" Mai 13 22:43:50 volumio go-librespot[9592]: time="2025-05-13T22:43:50+02:00" level=trace msg="received accesspoint pong ack" Mai 13 22:43:55 volumio go-librespot[9592]: time="2025-05-13T22:43:55+02:00" level=debug msg="fetched chunk 7/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:43:58 volumio go-librespot[9592]: time="2025-05-13T22:43:58+02:00" level=trace msg="sent dealer ping" Mai 13 22:43:58 volumio go-librespot[9592]: time="2025-05-13T22:43:58+02:00" level=trace msg="received dealer pong" Mai 13 22:44:07 volumio go-librespot[9592]: time="2025-05-13T22:44:07+02:00" level=debug msg="fetched chunk 8/28, size: 524288" uri="spotify:track:1FeoJDSHts21OhuWDZoHeZ" Mai 13 22:44:10 volumio volumio[9347]: info: [1747169050151] [80s80s] Pushing the next song state Book of Love - Boy and getting next track. Mai 13 22:44:10 volumio volumio[9347]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mai 13 22:44:10 volumio volumio[9347]: TypeError: Cannot set property 'name' of undefined Mai 13 22:44:10 volumio volumio[9347]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Mai 13 22:44:10 volumio volumio[9347]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Mai 13 22:44:10 volumio volumio[9347]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Mai 13 22:44:10 volumio volumio[9347]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Mai 13 22:44:10 volumio volumio[9347]: at processImmediate (internal/timers.js:461:21) Mai 13 22:44:10 volumio volumio[9347]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mai 13 22:44:10 volumio sudo[17119]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-13 22:43 Mai 13 22:44:10 volumio sudo[17119]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 11 May 2025 08:08:19 PM CEST" VOLUMIO_VERSION="3.809" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="246e2a37c1e527921b1850b7be948406"