-- Logs begin at Thu 2024-09-05 11:40:25 BST, end at Thu 2024-10-03 17:25:57 BST. -- Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1363" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=trace msg="closed output device because of stop command" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=debug msg="renewing login5 access token" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=debug msg="authenticated as pg9989" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=debug msg="put connect state inactive" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=trace msg="emitting websocket event: inactive" Oct 03 17:25:55 volumio go-librespot[924]: time="2024-10-03T17:25:55+01:00" level=trace msg="emitting websocket event: stopped" Oct 03 17:25:55 volumio volumio[691]: SPOTIFY: received: {"type":"inactive","data":null} Oct 03 17:25:55 volumio volumio[691]: error: Failed to decode event: inactive Oct 03 17:25:55 volumio volumio[691]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Oct 03 17:25:55 volumio volumio[691]: SPOTIFY: PUSH STATE SPOTIFY Oct 03 17:25:55 volumio volumio[691]: SPOTIFY: {"status":"stop","service":"spop","title":"Until The Night Fades","artist":"Etty Lau Farrell, Hyper","album":"Until The Night Fades","albumart":"https://i.scdn.co/image/ab67616d00001e02546b402d4e5f64bac7f3402c","uri":"spotify:track:6sRfY7dn8NMo6IrVJEXpAP","trackType":"spotify","seek":1,"duration":197,"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 03 17:25:55 volumio volumio[691]: info: CoreCommandRouter::servicePushState Oct 03 17:25:55 volumio volumio[691]: info: CoreStateMachine::pushState Oct 03 17:25:55 volumio volumio[691]: info: CorePlayQueue::getTrack 0 Oct 03 17:25:56 volumio volumio[691]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 17:25:56 volumio volumio[691]: TypeError: Cannot read property 'name' of undefined Oct 03 17:25:56 volumio volumio[691]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) Oct 03 17:25:56 volumio volumio[691]: at CoreStateMachine.pushState (/volumio/app/statemachine.js:522:20) Oct 03 17:25:56 volumio volumio[691]: at CoreStateMachine.syncState (/volumio/app/statemachine.js:592:10) Oct 03 17:25:56 volumio volumio[691]: at CoreCommandRouter.servicePushState (/volumio/app/index.js:413:28) Oct 03 17:25:56 volumio volumio[691]: at ControllerSpotify.pushState (/data/plugins/music_service/spop/index.js:430:31) Oct 03 17:25:56 volumio volumio[691]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:320:14) Oct 03 17:25:56 volumio volumio[691]: at WebSocket.message (/data/plugins/music_service/spop/index.js:190:14) Oct 03 17:25:56 volumio volumio[691]: at WebSocket.emit (events.js:315:20) Oct 03 17:25:56 volumio volumio[691]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1220:20) Oct 03 17:25:56 volumio volumio[691]: at Receiver.emit (events.js:315:20) Oct 03 17:25:56 volumio volumio[691]: at Receiver.dataMessage (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:596:14) Oct 03 17:25:56 volumio volumio[691]: at Receiver.getData (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:496:10) Oct 03 17:25:56 volumio volumio[691]: at Receiver.startLoop (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:167:16) Oct 03 17:25:56 volumio volumio[691]: at Receiver._write (/data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:94:10) Oct 03 17:25:56 volumio volumio[691]: at writeOrBuffer (internal/streams/writable.js:358:12) Oct 03 17:25:56 volumio volumio[691]: at Receiver.Writable.write (internal/streams/writable.js:303:10) Oct 03 17:25:56 volumio volumio[691]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=error msg="failed receiving dealer message" error="failed to get reader: received close frame: status = StatusGoingAway and reason = \"\"" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=error msg="failed receiving packet" error="failed reading packet header: read tcp 192.168.1.128:52992->104.199.65.9:4070: use of closed network connection" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=debug msg="obtained new client token: AAAYA28c41JcbwbwJMaP5P7yiWcLESoXMwdqN8lt6OrfWu2PWmQKzHqUJoRWTIZ3vL7eC1ab2eyES+XBRvTlSJ99f4d3x8QO7jezUTj6/EuRg4AQsDjImO9vERu455/bLhLPWlHR5GZR1BH08gC71KNRkfm8O1kkiqjCB1HZrXYtKo8etOYC9wFG78TRrKQvB3ctETqie/LGKByRrYO8OimxtHfJwNic9Gbh/5ORotawT7s+WFNssiwaNZ6h" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+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-gae2.spotify.com:80]" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=info msg="connected to ap-gew1.spotify.com:4070" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=debug msg="completed keyexchange" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=debug msg="completed challenge" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=debug msg="authenticated as pg9989" Oct 03 17:25:56 volumio go-librespot[924]: time="2024-10-03T17:25:56+01:00" level=debug msg="authenticated as pg9989" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="dealer connection opened" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="restored session after logout, username: pg9989" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 505" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="autoplay enabled: false" Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="received connection id: Y2VmYzBhNzQtYTdjMS00Yzc2LWIzMTgtNzQ2YTU4M2MwM2Y0K2RlYWxlcit0Y3A6Ly8wYWNhNDMyZC5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMkRERjAzQ0EyRjM0MzQ5NUFEMDlFOEYwM0Q3M0Y3NDkzRENFNjc2RDE1NEIwMkI0QkI0OUEyNUUyOTY5RTVFMw==" Oct 03 17:25:57 volumio sudo[22195]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-03 17:24 Oct 03 17:25:57 volumio sudo[22195]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 03 17:25:57 volumio go-librespot[924]: time="2024-10-03T17:25:57+01:00" level=debug msg="put connect state because NEW_DEVICE" 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"