-- Logs begin at Thu 2019-02-14 11:11:58 CET, end at Tue 2025-06-03 21:22:35 CEST. -- Jun 03 21:21:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:07+02:00" level=trace msg="sent dealer ping" Jun 03 21:21:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:07+02:00" level=trace msg="received dealer pong" Jun 03 21:21:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:07+02:00" level=trace msg="received accesspoint ping" Jun 03 21:21:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:07+02:00" level=trace msg="received accesspoint pong ack" Jun 03 21:21:37 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:37+02:00" level=trace msg="sent dealer ping" Jun 03 21:21:37 linus-volumio go-librespot[1243]: time="2025-06-03T21:21:37+02:00" level=trace msg="received dealer pong" Jun 03 21:22:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:07+02:00" level=trace msg="sent dealer ping" Jun 03 21:22:07 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:07+02:00" level=trace msg="received dealer pong" Jun 03 21:22:28 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:28+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 03 21:22:28 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:28+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 03 21:22:28 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Jun 03 21:22:28 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1729" Jun 03 21:22:30 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:30+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 03 21:22:30 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:30+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 338" Jun 03 21:22:32 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:32+02:00" level=debug msg="handling transfer player command from 1cc9bbd4af41c2fa64d72782cdc1e37a00fb3ca9" Jun 03 21:22:32 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:32+02:00" level=debug msg="renewing login5 access token" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=info msg="authenticated Login5 as tube.mlg.hd" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="resolved context of track" uri="spotify:album:72aiMSxFyKAiY4mrolRPgj" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:album:72aiMSxFyKAiY4mrolRPgj" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="loading track (paused: false, position: 16495ms)" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=trace msg="emitting websocket event: will_play" Jun 03 21:22:33 linus-volumio volumio[1004]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7gv9Ky47iGM6LRp5aO5tkt","play_origin":"album"}} Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="selected format OGG_VORBIS_320 (b3cf1aded54039589fd289d2cd10975f4e6f0dcc)" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="requested aes key for file b3cf1aded54039589fd289d2cd10975f4e6f0dcc, gid: 7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:33 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:33+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1676" Jun 03 21:22:34 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:34+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1287" Jun 03 21:22:34 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:34+02:00" level=debug msg="fetched first chunk of 14, total size is 6967458 bytes" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:34 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:34+02:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:34 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:34+02:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=trace msg="seek to 16495ms (diff: 123ms, samples: 727429, bytes: 886870)" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="created new output device" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+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" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=info msg="loaded track \"Vannacht Slaap Jij Bij Mij\" (paused: false, position: 16495ms, duration: 148704ms, prefetched: false)" uri="spotify:track:7gv9Ky47iGM6LRp5aO5tkt" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=trace msg="scheduling prefetch in 102s" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=trace msg="emitting websocket event: metadata" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=trace msg="emitting websocket event: active" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="sending successful reply for dealer request" Jun 03 21:22:35 linus-volumio volumio[1004]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7gv9Ky47iGM6LRp5aO5tkt","name":"Vannacht Slaap Jij Bij Mij","artist_names":["Afro Bros","John West","Billy Dans","Monq"],"album_name":"Vannacht Slaap Jij Bij Mij","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0297d28853ed5a204ef767abd5","position":16495,"duration":148704,"release_date":"year:2024 month:6 day:28","track_number":1,"disc_number":1}} Jun 03 21:22:35 linus-volumio volumio[1004]: SPOTIFY: received: {"type":"active","data":null} Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 03 21:22:35 linus-volumio volumio[1004]: info: Aligning Spotify Volume to Volumio Volume Jun 03 21:22:35 linus-volumio volumio[1004]: info: CoreCommandRouter::volumioGetState Jun 03 21:22:35 linus-volumio volumio[1004]: info: CorePlayQueue::getTrack 0 Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 03 21:22:35 linus-volumio volumio[1004]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 03 21:22:35 linus-volumio volumio[1004]: TypeError: Cannot read property 'name' of undefined Jun 03 21:22:35 linus-volumio volumio[1004]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Jun 03 21:22:35 linus-volumio volumio[1004]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) Jun 03 21:22:35 linus-volumio volumio[1004]: at ControllerSpotify.alignSpotifyVolumeToVolumioVolume (/data/plugins/music_service/spop/index.js:598:36) Jun 03 21:22:35 linus-volumio volumio[1004]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:288:18) Jun 03 21:22:35 linus-volumio volumio[1004]: at WebSocket.message (/data/plugins/music_service/spop/index.js:193:14) Jun 03 21:22:35 linus-volumio volumio[1004]: at WebSocket.emit (events.js:315:20) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.emit (events.js:315:20) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Jun 03 21:22:35 linus-volumio volumio[1004]: at writeOrBuffer (internal/streams/writable.js:358:12) Jun 03 21:22:35 linus-volumio volumio[1004]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Jun 03 21:22:35 linus-volumio volumio[1004]: at Socket.socketOnData (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1355:35) Jun 03 21:22:35 linus-volumio volumio[1004]: at Socket.emit (events.js:315:20) Jun 03 21:22:35 linus-volumio volumio[1004]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 03 21:22:35 linus-volumio go-librespot[1243]: time="2025-06-03T21:22:35+02:00" level=trace msg="emitting websocket event: playing" Jun 03 21:22:35 linus-volumio sudo[4383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-03 21:21 Jun 03 21:22:35 linus-volumio sudo[4383]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"