-- Logs begin at Wed 2025-10-22 04:53:10 AEDT, end at Sun 2025-10-26 10:56:49 AEDT. -- Oct 26 10:55:10 volumio go-librespot[1209]: time="2025-10-26T10:55:10+11:00" level=trace msg="sent dealer ping" Oct 26 10:55:10 volumio go-librespot[1209]: time="2025-10-26T10:55:10+11:00" level=trace msg="received dealer pong" Oct 26 10:55:17 volumio go-librespot[1209]: time="2025-10-26T10:55:17+11:00" level=trace msg="emitting websocket event: not_playing" Oct 26 10:55:17 volumio go-librespot[1209]: time="2025-10-26T10:55:17+11:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7EroGeDg1uteOaQ45Ftfiz" Oct 26 10:55:17 volumio volumio[841]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:7rXke3ttpL2uXel9Nesf4u","play_origin":"playlist"}} Oct 26 10:55:17 volumio volumio[841]: error: Failed to decode event: not_playing Oct 26 10:55:17 volumio go-librespot[1209]: time="2025-10-26T10:55:17+11:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 10:55:17 volumio go-librespot[1209]: time="2025-10-26T10:55:17+11:00" level=trace msg="emitting websocket event: will_play" Oct 26 10:55:17 volumio go-librespot[1209]: time="2025-10-26T10:55:17+11:00" level=info msg="loaded track \"I Remember - John Summit Remix\" (paused: false, position: 0ms, duration: 240000ms, prefetched: true)" uri="spotify:track:7EroGeDg1uteOaQ45Ftfiz" Oct 26 10:55:17 volumio volumio[841]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","play_origin":"playlist"}} Oct 26 10:55:18 volumio go-librespot[1209]: time="2025-10-26T10:55:18+11:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 10:55:18 volumio go-librespot[1209]: time="2025-10-26T10:55:18+11:00" level=trace msg="scheduling prefetch in 210s" Oct 26 10:55:18 volumio go-librespot[1209]: time="2025-10-26T10:55:18+11:00" level=trace msg="emitting websocket event: metadata" Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","name":"I Remember - John Summit Remix","artist_names":["deadmau5","Kaskade","John Summit"],"album_name":"I Remember (John Summit Remix)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021d0829e89921438f9729f5ef","position":0,"duration":240000,"release_date":"year:2023 month:7 day:7","track_number":1,"disc_number":1}} Oct 26 10:55:18 volumio go-librespot[1209]: time="2025-10-26T10:55:18+11:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 26 10:55:18 volumio go-librespot[1209]: time="2025-10-26T10:55:18+11:00" level=trace msg="emitting websocket event: playing" Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","resume":false,"play_origin":"playlist"}} Oct 26 10:55:18 volumio volumio[841]: info: Spotify is playing in volatile mode Oct 26 10:55:18 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: UNSET VOLATILE Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: {"status":"play","position":0,"title":"James Hype - Ibiza sunset - 5 deck mix","artist":"James Hype","album":"YouTube","albumart":"https://i.ytimg.com/vi/djSVcKjn-0k/hq720.jpg?sqp=-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg==&rs=AOn4CLBHprKGywu5yEwfjoF_KDbMiJ_zCQ","uri":"youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22djSVcKjn-0k%22%2C%22playlistId%22%3A%22RDdjSVcKjn-0k%22%2C%22params%22%3A%22OAHAAQGqAw5KYW1lcyBoeXBlIHNldLoDCgiH0pTAhc-Apl26AwoIoqmIp93854IIugMLCMzQiovan-GstgG6AyQSIlBMNFhwbml2c1hKWE9nQy02d1hGeFRfQ2o0eklXYjlzWlG6AwsIvoCxt86Cl5S1AboDCgiJgqj2w8WOgwe6AwoI7-iBwb6evpMvugMLCO-Vm_X0rYnuyAG6Aw8SDVJEWFV3Q2VGZ0ZLUWO6AwoI-6_aqIasiLJ6ugMKCK6s84DxlqHASLoDCwiOld6I37L5jbQBugMLCJnN8_3Pg-nq7gG6AwoIs72E-7vY1dtRugMLCOv6i9uFtNiOzgG6AwsItuHulv6nofK0AboDCwjZktHRpuqK_JgB8gMFDSEewT24BQE%253D%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22James%20Hype%20-%20Ibiza%20sunset%20-%205%20deck%20mix%22%2C%22artist%22%3A%22James%20Hype%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FdjSVcKjn-0k%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLBHprKGywu5yEwfjoF_KDbMiJ_zCQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22djSVcKjn-0k%22%2C%22playlistId%22%3A%22RDdjSVcKjn-0k%22%2C%22params%22%3A%22OAHAAQGqAw5KYW1lcyBoeXBlIHNldLoDCgiH0pTAhc-Apl26AwoIoqmIp93854IIugMLCMzQiovan-GstgG6AyQSIlBMNFhwbml2c1hKWE9nQy02d1hGeFRfQ2o0eklXYjlzWlG6AwsIvoCxt86Cl5S1AboDCgiJgqj2w8WOgwe6AwoI7-iBwb6evpMvugMLCO-Vm_X0rYnuyAG6Aw8SDVJEWFV3Q2VGZ0ZLUWO6AwoI-6_aqIasiLJ6ugMKCK6s84DxlqHASLoDCwiOld6I37L5jbQBugMLCJnN8_3Pg-nq7gG6AwoIs72E-7vY1dtRugMLCOv6i9uFtNiOzgG6AwsItuHulv6nofK0AboDCwjZktHRpuqK_JgB8gMFDSEewT24BQE%253D%22%7D%7D%7D","seek":0,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"updatedb":false,"volatile":false,"service":"youtube2"} Oct 26 10:55:18 volumio volumio[841]: info: Setting Spotify stop after unset volatile call Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: {"status":"play","service":"spop","title":"I Remember - John Summit Remix","artist":"deadmau5, Kaskade, John Summit","album":"I Remember (John Summit Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021d0829e89921438f9729f5ef","uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","trackType":"spotify","seek":0,"duration":240,"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 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:55:18 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: {"status":"play","service":"spop","title":"I Remember - John Summit Remix","artist":"deadmau5, Kaskade, John Summit","album":"I Remember (John Summit Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021d0829e89921438f9729f5ef","uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","trackType":"spotify","seek":1000,"duration":240,"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 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:55:18 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 10:55:18 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:55:18 volumio volumio[841]: info: Spotify Stop Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: SPOTIFY STOP Oct 26 10:55:18 volumio volumio[841]: SPOTIFY: {"status":"play","title":"I Remember - John Summit Remix","artist":"deadmau5, Kaskade, John Summit","album":"I Remember (John Summit Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021d0829e89921438f9729f5ef","uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","trackType":"spotify","codec":"ogg","seek":1000,"duration":240,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Oct 26 10:55:26 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 10:55:26 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 10:55:26 volumio volumio[841]: info: Discovery: Getting this device information Oct 26 10:55:26 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:55:26 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 10:55:32 volumio go-librespot[1209]: time="2025-10-26T10:55:32+11:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:7EroGeDg1uteOaQ45Ftfiz" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=info msg="playback was transferred to Pixel 9" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=trace msg="closed output device because of stop command" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="put connect state inactive" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=trace msg="emitting websocket event: inactive" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=trace msg="emitting websocket event: stopped" Oct 26 10:55:36 volumio volumio[841]: SPOTIFY: received: {"type":"inactive","data":null} Oct 26 10:55:36 volumio volumio[841]: error: Failed to decode event: inactive Oct 26 10:55:36 volumio volumio[841]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Oct 26 10:55:36 volumio volumio[841]: SPOTIFY: PUSH STATE SPOTIFY Oct 26 10:55:36 volumio volumio[841]: SPOTIFY: {"status":"stop","service":"spop","title":"I Remember - John Summit Remix","artist":"deadmau5, Kaskade, John Summit","album":"I Remember (John Summit Remix)","albumart":"https://i.scdn.co/image/ab67616d00001e021d0829e89921438f9729f5ef","uri":"spotify:track:7EroGeDg1uteOaQ45Ftfiz","trackType":"spotify","seek":18000,"duration":240,"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 26 10:55:36 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:55:36 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:55:36 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 10:55:36 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:55:36 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 26 10:55:36 volumio volumio[841]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current youtube2 Received spop Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 377" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="dealer connection closed" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="dealer recv loop stopped" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="obtained new client token: AACTRMUneOTtuXv0fTXgk5kY16cKITVaEKtoZMk/oBgtYS3II9OdJ8T2sJOmXB6cb7oiVzHbhTGSO8Esh43E86Bf9keQRhLeb7ltg1ucK7n933Lxuv70fY7sYCahKpkttb47m8N+BUrhEOlkVV/ff8dwqbIawqBgdjt+ALZ2scy/DPHXZ0l+n2DPRZQ9HuZTpgK0LM3vRU7TyjL6d+yw8n4E/yz+RqiEyct5oF+D6A3Ew10oxSiW+mruAGRu" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="completed keyexchange" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=debug msg="completed challenge" Oct 26 10:55:36 volumio go-librespot[1209]: time="2025-10-26T10:55:36+11:00" level=info msg="authenticated AP" username="im**********au" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=info msg="authenticated Login5" username="im**********au" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="restored session after logout" username="im**********au" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="dealer connection opened" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=trace msg="starting accesspoint recv loop" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=trace msg="starting dealer recv loop" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=trace msg="received accesspoint ping" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="received connection id: NWQ0YTEyM2MtNjk1...RUQyRUVENzg4OQ==" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=trace msg="received accesspoint pong ack" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="put connect state because NEW_DEVICE" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="update volume requested to 65535/65535" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 26 10:55:37 volumio go-librespot[1209]: time="2025-10-26T10:55:37+11:00" level=trace msg="emitting websocket event: volume" Oct 26 10:55:37 volumio volumio[841]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Oct 26 10:55:37 volumio volumio[841]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Oct 26 10:55:39 volumio go-librespot[1209]: time="2025-10-26T10:55:39+11:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 26 10:55:39 volumio go-librespot[1209]: time="2025-10-26T10:55:39+11:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 377" Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: info: Retrieving Cloud Streaming UI Oct 26 10:55:45 volumio volumio[841]: info: Getting Tidal Cloud Configuration Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: info: Getting Qobuz Cloud Configuration Oct 26 10:55:45 volumio volumio[841]: info: Asking plugin for UI Config Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: info: Getting Spotify Cloud Configuration Oct 26 10:55:45 volumio volumio[841]: info: Asking plugin for UI Config Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: info: Saving Spotify Acccount Oct 26 10:55:45 volumio volumio[841]: info: Got Tidal Cloud Configuration Oct 26 10:55:45 volumio volumio[841]: info: Got it Oct 26 10:55:45 volumio volumio[841]: info: Got it Oct 26 10:55:45 volumio volumio[841]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:55:45 volumio volumio[841]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::volumioGetBrowseSources Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 10:55:45 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 26 10:55:49 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 10:55:54 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 26 10:55:55 volumio volumio[841]: info: [yt-cast-receiver] Connecting sender through DIAL... Oct 26 10:55:56 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 10:55:56 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 10:55:56 volumio volumio[841]: info: Discovery: Getting this device information Oct 26 10:55:56 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:55:56 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 10:55:57 volumio volumio[841]: info: [yt-cast-receiver] (YouTube) Sender connected: GOOGLE Pixel 9 (user: Imraan) Oct 26 10:55:57 volumio volumio[841]: info: [ytcr] ***** Sender connected ***** Oct 26 10:55:57 volumio volumio[841]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 26 10:56:04 volumio volumio[841]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Oct 26 10:56:07 volumio go-librespot[1209]: time="2025-10-26T10:56:07+11:00" level=trace msg="sent dealer ping" Oct 26 10:56:07 volumio go-librespot[1209]: time="2025-10-26T10:56:07+11:00" level=trace msg="received dealer pong" Oct 26 10:56:14 volumio volumio[841]: info: [yt-cast-receiver] Player.play(): Ojw5OHHCk2I @ 0s Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioStop Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::stop Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::serviceStop Oct 26 10:56:14 volumio volumio[841]: info: Received STOP, but no service to execute it Oct 26 10:56:14 volumio volumio[841]: info: [ytcr] InnertubeLoader: creating Innertube instance... Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:14 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:56:14 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:14 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:14 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 26 10:56:14 volumio volumio[841]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current youtube2 Received ytcr Oct 26 10:56:15 volumio volumio[841]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Oct 26 10:56:23 volumio volumio[841]: info: [ytcr] InnertubeLoader: obtaining po_token by visitorData... Oct 26 10:56:23 volumio volumio[841]: info: CoreCommandRouter::volumioVolatilePlay Oct 26 10:56:23 volumio volumio[841]: info: CoreStateMachine::volatilePlay Oct 26 10:56:23 volumio volumio[841]: info: WARNING: No play method for volatile plugin undefined Oct 26 10:56:23 volumio volumio[841]: verbose: New Socket.io Connection to 192.168.1.126:3000 from 192.168.1.140 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Oct 26 10:56:23 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 10:56:23 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 10:56:23 volumio volumio[841]: info: Discovery: Getting this device information Oct 26 10:56:23 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:23 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 10:56:24 volumio volumio[841]: verbose: New Socket.io Connection to 192.168.1.126:3000 from 192.168.1.140 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 26 10:56:24 volumio volumio[841]: info: [ytcr] InnertubeLoader: obtained po_token (expires in 43200 seconds) Oct 26 10:56:24 volumio volumio[841]: info: [ytcr] InnertubeLoader: re-create Innertube instance with po_token Oct 26 10:56:24 volumio volumio[841]: info: [ytcr] InnertubeLoader: creating Innertube instance with po_token... Oct 26 10:56:25 volumio volumio[841]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Oct 26 10:56:32 volumio volumio[841]: info: [ytcr] InnertubeLoader: going to refresh po_token in 43100 seconds Oct 26 10:56:32 volumio volumio[841]: info: [ytcr] InnertubeLoader: creating Innertube instance... Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 26 10:56:32 volumio volumio[841]: info: Discovery: Getting this device information Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::volumioGetState Oct 26 10:56:32 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 26 10:56:33 volumio volumio[841]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Oct 26 10:56:37 volumio go-librespot[1209]: time="2025-10-26T10:56:37+11:00" level=trace msg="sent dealer ping" Oct 26 10:56:37 volumio go-librespot[1209]: time="2025-10-26T10:56:37+11:00" level=trace msg="received dealer pong" Oct 26 10:56:40 volumio volumio[841]: info: [ytcr] InnertubeLoader: obtaining po_token by visitorData... Oct 26 10:56:41 volumio volumio[841]: info: [ytcr] InnertubeLoader: obtained po_token (expires in 43200 seconds) Oct 26 10:56:41 volumio volumio[841]: info: [ytcr] InnertubeLoader: re-create Innertube instance with po_token Oct 26 10:56:41 volumio volumio[841]: info: [ytcr] InnertubeLoader: creating Innertube instance with po_token... Oct 26 10:56:41 volumio volumio[841]: info: CoreCommandRouter::volumioGetQueue Oct 26 10:56:41 volumio volumio[841]: info: CoreStateMachine::getQueue Oct 26 10:56:41 volumio volumio[841]: info: CorePlayQueue::getQueue Oct 26 10:56:42 volumio volumio[841]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Oct 26 10:56:48 volumio volumio[841]: info: [ytcr] InnertubeLoader: going to refresh po_token in 43100 seconds Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::volumioPlay Oct 26 10:56:48 volumio volumio[841]: verbose: UNSET VOLATILE: Service: undefined Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::servicePushState Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:48 volumio volumio[841]: info: [yt-cast-receiver] Player.stop() Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::play index 0 Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::volumioRemoveQueueItem Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::removeQueueItem Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::stop Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::updateTrackBlock Oct 26 10:56:48 volumio volumio[841]: info: CorePlayQueue::getTrackBlock Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::stPlaybackTimer Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::pushState Oct 26 10:56:48 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::volumioPushState Oct 26 10:56:48 volumio volumio[841]: info: CoreStateMachine::serviceStop Oct 26 10:56:48 volumio volumio[841]: info: CorePlayQueue::getTrack 0 Oct 26 10:56:48 volumio volumio[841]: info: CoreCommandRouter::serviceStop Oct 26 10:56:48 volumio volumio[841]: error: WARNING: No stop method for service youtube2 Oct 26 10:56:48 volumio volumio[841]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 10:56:48 volumio volumio[841]: TypeError: Cannot read property 'then' of undefined Oct 26 10:56:48 volumio volumio[841]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1370:7) Oct 26 10:56:48 volumio volumio[841]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) Oct 26 10:56:48 volumio volumio[841]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) Oct 26 10:56:48 volumio volumio[841]: at Socket.emit (events.js:315:20) Oct 26 10:56:48 volumio volumio[841]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 26 10:56:48 volumio volumio[841]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 26 10:56:48 volumio volumio[841]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 26 10:56:49 volumio sudo[1638]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-26 10:55 Oct 26 10:56:49 volumio sudo[1638]: 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="95d9088e5dcb3a55aabfe7f209b9ae00946f3ec5" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9a3927796ae9ab3a5a247866bf574288cd09ee64" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 04 Sep 2025 04:11:35 PM CEST" VOLUMIO_VERSION="3.845" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d8c10ad904a299b47c7499a1cf239286"