-- Logs begin at Thu 2024-09-05 11:40:25 BST, end at Fri 2024-10-04 18:17:03 BST. -- Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1363" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=trace msg="closed output device because of stop command" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="renewing login5 access token" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="authenticated as pg9989" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="put connect state inactive" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=trace msg="emitting websocket event: inactive" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=trace msg="emitting websocket event: stopped" Oct 04 18:17:02 volumio volumio[699]: SPOTIFY: received: {"type":"inactive","data":null} Oct 04 18:17:02 volumio volumio[699]: error: Failed to decode event: inactive Oct 04 18:17:02 volumio volumio[699]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Oct 04 18:17:02 volumio volumio[699]: SPOTIFY: PUSH STATE SPOTIFY Oct 04 18:17:02 volumio volumio[699]: SPOTIFY: {"status":"stop","service":"spop","title":"TB Reality (Mixed)","artist":"Plump DJs","album":"RePlumped","albumart":"https://i.scdn.co/image/ab67616d00001e025e0624aeccb9c4f5fcea72fd","uri":"spotify:track:0quv81CsyO2PDTHGQBB0NO","trackType":"spotify","seek":110000,"duration":115,"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 04 18:17:02 volumio volumio[699]: info: CoreCommandRouter::servicePushState Oct 04 18:17:02 volumio volumio[699]: info: CoreStateMachine::pushState Oct 04 18:17:02 volumio volumio[699]: info: CorePlayQueue::getTrack 0 Oct 04 18:17:02 volumio volumio[699]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 18:17:02 volumio volumio[699]: TypeError: Cannot read property 'name' of undefined Oct 04 18:17:02 volumio volumio[699]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Oct 04 18:17:02 volumio volumio[699]: at CoreStateMachine.pushState (/volumio/app/statemachine.js:522:20) Oct 04 18:17:02 volumio volumio[699]: at CoreStateMachine.syncState (/volumio/app/statemachine.js:592:10) Oct 04 18:17:02 volumio volumio[699]: at CoreCommandRouter.servicePushState (/volumio/app/index.js:413:28) Oct 04 18:17:02 volumio volumio[699]: at ControllerSpotify.pushState (/data/plugins/music_service/spop/index.js:430:31) Oct 04 18:17:02 volumio volumio[699]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:320:14) Oct 04 18:17:02 volumio volumio[699]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Oct 04 18:17:02 volumio volumio[699]: at WebSocket.emit (events.js:315:20) Oct 04 18:17:02 volumio volumio[699]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 04 18:17:02 volumio volumio[699]: at Receiver.emit (events.js:315:20) Oct 04 18:17:02 volumio volumio[699]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 04 18:17:02 volumio volumio[699]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 04 18:17:02 volumio volumio[699]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 04 18:17:02 volumio volumio[699]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 04 18:17:02 volumio volumio[699]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 04 18:17:02 volumio volumio[699]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 04 18:17:02 volumio volumio[699]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.128:34470->104.199.65.9:443: use of closed network connection" Oct 04 18:17:02 volumio go-librespot[928]: time="2024-10-04T18:17:02+01:00" level=debug msg="obtained new client token: AAAfvgH2xsCr7zrh/OrjC3MFGqRggU3sFA42tBBFCP1Muu30q6vTsGzIwVy0ucP05nqgfjOF6h77dyWy8OxDsuRin6hppv0lqwn8Vz+81f6f025hGWOlEGRbN0CyyoklOu3tlRDMyujsLNeBJL3uv9mjh886m1F1ZCaX7OknXt9Pw/O7fJ1i8V/WQzsLXdmJ8hmKOs9rR2VPj2asX2ybGpK+ILU6nnNClHHxiZ2t++u5wOK65T/lnxLzocImDp8=" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=info msg="connected to ap-gew1.spotify.com:4070" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="completed keyexchange" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="completed challenge" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="authenticated as pg9989" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="authenticated as pg9989" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="dealer connection opened" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="restored session after logout, username: pg9989" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="autoplay enabled: false" Oct 04 18:17:03 volumio go-librespot[928]: time="2024-10-04T18:17:03+01:00" level=debug msg="received connection id: ODM5NjNjYmYtOTc3Yi00YzFiLTljZWYtMGM1ZmEzYWIzOGE4K2RlYWxlcit0Y3A6Ly8wYWNhNDA2NC5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArODU0REREQTM1MjA0NDA5QUZBMUUxRUJDNEE1NzY4NDBCQUJERTZDNzI1QjlDREY3RDkxMEJDMUE1RUNENEI0Mg==" Oct 04 18:17:03 volumio sudo[24557]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-04 18:16 Oct 04 18:17:03 volumio sudo[24557]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"