Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 93) (YouTube) Incoming message: 'noop' Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 93) (YouTube) Not handled: 'noop' Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting... Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=93&CI=0&RID=rpc&SID=9A4D615B674D36F7&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=86ssgD89Vq-79-ynnnQzqx6Gum-8wH7b&id=7f44c6cc-e42a-4caf-8d3e-342453729fe3&loungeIdToken=AGdO5p-iG6eXQB8jCX4s0pNEDwCS__5cWuCwjJOmEqRYPs_Tg6iSwIfBZ3t-Rikpw6T1B6_xg_Xbszx1dw90zDXJ6HwpQJqXeOKSpaQCRQK7cE1VTZ3BcMA&mdxVersion=2&name=YouTube%20on%20VolumioRA1&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=0c2d0a37f97e Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] RPC connection established. Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 94) (YouTube) Incoming message: 'noop' Dec 15 17:16:01 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 94) (YouTube) Not handled: 'noop' Dec 15 17:16:09 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:09 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 94) (YouTube Music) Incoming message: 'noop' Dec 15 17:16:09 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 94) (YouTube Music) Not handled: 'noop' Dec 15 17:16:09 volumiora1 volumio[1326]: verbose: New Socket.io Connection to k0ck3ikoegay2hhm9esplx2eiom1-177b2bad8dbf7504ec19b8d7eafe365b.eu2.myvolumio.org from 127.0.0.1 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Dec 15 17:16:09 volumiora1 sudo[7528]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 17:16:09 volumiora1 sudo[7528]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 17:16:09 volumiora1 sudo[7528]: pam_unix(sudo:session): session closed for user root Dec 15 17:16:09 volumiora1 sudo[7530]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 17:16:09 volumiora1 sudo[7530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 17:16:09 volumiora1 sudo[7530]: pam_unix(sudo:session): session closed for user root Dec 15 17:16:09 volumiora1 volumio[1326]: verbose: New Socket.io Connection to 192.168.10.251 from 192.168.10.157 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Dec 15 17:16:09 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 15 17:16:09 volumiora1 volumio[1326]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 15 17:16:09 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetState Dec 15 17:16:09 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetVisibleSources Dec 15 17:16:09 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 17:16:09 volumiora1 volumio[1326]: info: Listing playlists Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 8 Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 9 Dec 15 17:16:15 volumiora1 volumio[1326]: info: Prefetching next song Dec 15 17:16:15 volumiora1 volumio[1326]: info: [ytmusic] Obtained PO token for video #-KjOMY_zxrA: MlUJ4jQfMkyDGgncpN_vGjRYn2LnnAnmrzUlWG2FbAuzKiDdM-YXUiJ4XD_Ci1DrkRrIe5pV1TV4cHnzhXThh7LMPJra98rxIeDI2ZAWtWB-8WOoPtSm Dec 15 17:16:15 volumiora1 volumio[1326]: info: [ytmusic] (Cold) validating stream URL "https://rr2---sn-uqj-j2ik.googlevideo.com/videoplayback?expire=1765836975&ei=TzRAaZOAHJDCv_IPnuvWuAQ&ip=89.150.135.56&id=o-AGnOHN4I_-ZsN-HusY6l8rYeA4lmE1jATfR82q8sdBAS&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=78&met=1765815375%2C&mh=vh&mm=31%2C29&mn=sn-uqj-j2ik%2Csn-5goeenez&ms=au%2Crdu&mv=m&mvi=2&pl=18&rms=au%2Cau&initcwndbps=4643750&bui=AYUSA3Aw0DqMlJuOgIG2sar46jVF7UL75j0CbGIBSHnf0te1B7xz3GmokZy03QmLxZiyiKklmu7AC2qI&spc=wH4QqzzKkVVNwzqyQa4ly84zqJYyqbG55_cfAhFfccL6esbTTw&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=h-5eppe8V8wWVBxH55gcrqwR&rqh=1&gir=yes&clen=3131320&dur=188.221&lmt=1763927882268684&mt=1765815004&fvip=4&keepalive=yes&fexp=51552689%2C51565115%2C51565682%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=hea2_hDzUMfX7A&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIgDHDieLsqoynFYtrm9BVvrsMC8sDyiaACsRVJzXrJxOsCIQDkyMI-6D_drrmpAtUfY6wPFG0GtnbmincNwfDdR9TUPw%3D%3D&sig=AJfQdSswRAIgOnAlfgc3g-QRHPjUUa-D_GRh3X4812nFOazV_YH7skYCIBeylo_UesxOfh7ApSgG8zHMoSJrtRZ_xTKumXMuGTrg&pot=MlUJ4jQfMkyDGgncpN_vGjRYn2LnnAnmrzUlWG2FbAuzKiDdM-YXUiJ4XD_Ci1DrkRrIe5pV1TV4cHnzhXThh7LMPJra98rxIeDI2ZAWtWB-8WOoPtSm&cver=1.20250219.01.00"... Dec 15 17:16:15 volumiora1 volumio[1326]: info: [ytmusic] (Cold) stream validated in 0.034s. Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand addid "https://rr2---sn-uqj-j2ik.googlevideo.com/videoplayback?expire=1765836975&ei=TzRAaZOAHJDCv_IPnuvWuAQ&ip=89.150.135.56&id=o-AGnOHN4I_-ZsN-HusY6l8rYeA4lmE1jATfR82q8sdBAS&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=78&met=1765815375%2C&mh=vh&mm=31%2C29&mn=sn-uqj-j2ik%2Csn-5goeenez&ms=au%2Crdu&mv=m&mvi=2&pl=18&rms=au%2Cau&initcwndbps=4643750&bui=AYUSA3Aw0DqMlJuOgIG2sar46jVF7UL75j0CbGIBSHnf0te1B7xz3GmokZy03QmLxZiyiKklmu7AC2qI&spc=wH4QqzzKkVVNwzqyQa4ly84zqJYyqbG55_cfAhFfccL6esbTTw&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=h-5eppe8V8wWVBxH55gcrqwR&rqh=1&gir=yes&clen=3131320&dur=188.221&lmt=1763927882268684&mt=1765815004&fvip=4&keepalive=yes&fexp=51552689%2C51565115%2C51565682%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=hea2_hDzUMfX7A&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIgDHDieLsqoynFYtrm9BVvrsMC8sDyiaACsRVJzXrJxOsCIQDkyMI-6D_drrmpAtUfY6wPFG0GtnbmincNwfDdR9TUPw%3D%3D&sig=AJfQdSswRAIgOnAlfgc3g-QRHPjUUa-D_GRh3X4812nFOazV_YH7skYCIBeylo_UesxOfh7ApSgG8zHMoSJrtRZ_xTKumXMuGTrg&pot=MlUJ4jQfMkyDGgncpN_vGjRYn2LnnAnmrzUlWG2FbAuzKiDdM-YXUiJ4XD_Ci1DrkRrIe5pV1TV4cHnzhXThh7LMPJra98rxIeDI2ZAWtWB-8WOoPtSm&cver=1.20250219.01.00&t.YouTube" Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand addid "https://rr2---sn-uqj-j2ik.googlevideo.com/videoplayback?expire=1765836975&ei=TzRAaZOAHJDCv_IPnuvWuAQ&ip=89.150.135.56&id=o-AGnOHN4I_-ZsN-HusY6l8rYeA4lmE1jATfR82q8sdBAS&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=78&met=1765815375%2C&mh=vh&mm=31%2C29&mn=sn-uqj-j2ik%2Csn-5goeenez&ms=au%2Crdu&mv=m&mvi=2&pl=18&rms=au%2Cau&initcwndbps=4643750&bui=AYUSA3Aw0DqMlJuOgIG2sar46jVF7UL75j0CbGIBSHnf0te1B7xz3GmokZy03QmLxZiyiKklmu7AC2qI&spc=wH4QqzzKkVVNwzqyQa4ly84zqJYyqbG55_cfAhFfccL6esbTTw&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=h-5eppe8V8wWVBxH55gcrqwR&rqh=1&gir=yes&clen=3131320&dur=188.221&lmt=1763927882268684&mt=1765815004&fvip=4&keepalive=yes&fexp=51552689%2C51565115%2C51565682%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=hea2_hDzUMfX7A&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&lsparams=cps%2Cmet%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=APaTxxMwRQIgDHDieLsqoynFYtrm9BVvrsMC8sDyiaACsRVJzXrJxOsCIQDkyMI-6D_drrmpAtUfY6wPFG0GtnbmincNwfDdR9TUPw%3D%3D&sig=AJfQdSswRAIgOnAlfgc3g-QRHPjUUa-D_GRh3X4812nFOazV_YH7skYCIBeylo_UesxOfh7ApSgG8zHMoSJrtRZ_xTKumXMuGTrg&pot=MlUJ4jQfMkyDGgncpN_vGjRYn2LnnAnmrzUlWG2FbAuzKiDdM-YXUiJ4XD_Ci1DrkRrIe5pV1TV4cHnzhXThh7LMPJra98rxIeDI2ZAWtWB-8WOoPtSm&cver=1.20250219.01.00&t.YouTube" took 1 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: MPD COMMAND [object Object] Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: MPD COMMAND [object Object] Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 2ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 1ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 1ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: [ytmusic-play] Prefetched and added track to MPD queue: Cold Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand consume 1 Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces system playlist update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Ignoring MPD Status Update Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces state update: options Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 1ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand consume 1 took 1 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::getState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand status Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 2ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 1ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces state update: options Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::getState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand status Dec 15 17:16:15 volumiora1 volumio[1326]: info: Dec 15 17:16:15 volumiora1 volumio[1326]: ---------------------------- MPD announces state update: options Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::getState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand status Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand status took 1 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand status took 1 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::parseState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::parseState Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::servicePushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 8 Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: CURRENT POSITION 8 Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState stateService stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState currentStatus play Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 9 Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::getState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::sendMpdCommand status Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::servicePushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 9 Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: CURRENT POSITION 9 Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState stateService stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState currentStatus stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: No code Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 47ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 46ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand status took 46 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: info: sendMpdCommand status took 39 milliseconds Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::parseState Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: ControllerMpd::parseState Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::servicePushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 9 Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: CURRENT POSITION 9 Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState stateService stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState currentStatus stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: No code Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: ControllerMpd::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::servicePushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: CorePlayQueue::getTrack 9 Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 15 17:16:15 volumiora1 volumio[1326]: verbose: CURRENT POSITION 9 Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState stateService stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::syncState currentStatus stop Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: No code Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreStateMachine::pushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioPushState Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output update for this device Dec 15 17:16:15 volumiora1 volumio[1326]: info: MRS: Pushing multiroomSync output Dec 15 17:16:15 volumiora1 volumio[1326]: info: ------------------------------ 93ms Dec 15 17:16:15 volumiora1 volumio[1326]: info: touch_display: Setting screensaver timeout to 188 seconds. Dec 15 17:16:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:16:16+01:00" level=trace msg="sent dealer ping" Dec 15 17:16:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:16:16+01:00" level=trace msg="received dealer pong" Dec 15 17:16:23 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 15 17:16:23 volumiora1 volumio[1326]: info: UPNP Browser: No servers found, reinitializing and searching... Dec 15 17:16:23 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetQueue Dec 15 17:16:23 volumiora1 volumio[1326]: info: CoreStateMachine::getQueue Dec 15 17:16:23 volumiora1 volumio[1326]: info: CorePlayQueue::getQueue Dec 15 17:16:26 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:26 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 95) (YouTube) Incoming message: 'noop' Dec 15 17:16:26 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 95) (YouTube) Not handled: 'noop' Dec 15 17:16:26 volumiora1 volumio[1326]: info: UPNP Browser: Returning 0 server(s) after 3s wait Dec 15 17:16:26 volumiora1 volumio[1326]: info: Preload queue cleared Dec 15 17:16:38 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:38 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 95) (YouTube Music) Incoming message: 'noop' Dec 15 17:16:38 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 95) (YouTube Music) Not handled: 'noop' Dec 15 17:16:39 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 15 17:16:39 volumiora1 volumio[1326]: info: UPNP Browser: No servers found, reinitializing and searching... Dec 15 17:16:42 volumiora1 volumio[1326]: info: UPNP Browser: Returning 0 server(s) after 3s wait Dec 15 17:16:42 volumiora1 volumio[1326]: info: Preload queue cleared Dec 15 17:16:46 volumiora1 go-librespot[1717]: time="2025-12-15T17:16:46+01:00" level=trace msg="sent dealer ping" Dec 15 17:16:46 volumiora1 go-librespot[1717]: time="2025-12-15T17:16:46+01:00" level=trace msg="received dealer pong" Dec 15 17:16:51 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:16:51 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 96) (YouTube) Incoming message: 'noop' Dec 15 17:16:51 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 96) (YouTube) Not handled: 'noop' Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: Retrieving Cloud Streaming UI Dec 15 17:16:53 volumiora1 volumio[1326]: info: Getting Tidal Cloud Configuration Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: Getting Qobuz Cloud Configuration Dec 15 17:16:53 volumiora1 volumio[1326]: info: Asking plugin for UI Config Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: Getting Spotify Cloud Configuration Dec 15 17:16:53 volumiora1 volumio[1326]: info: Asking plugin for UI Config Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: Saving Spotify Acccount Dec 15 17:16:53 volumiora1 volumio[1326]: info: Got it Dec 15 17:16:53 volumiora1 volumio[1326]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Dec 15 17:16:53 volumiora1 volumio[1326]: info: Got it Dec 15 17:16:53 volumiora1 volumio[1326]: info: Got Tidal Cloud Configuration Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::getUIConfigOnPlugin Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::volumioGetBrowseSources Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:16:53 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Dec 15 17:16:57 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:01 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:05 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 96) (YouTube Music) Incoming message: 'noop' Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 96) (YouTube Music) Not handled: 'noop' Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] RPC connection disconnected. Reconnecting... Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] Connecting to RPC URL: https://www.youtube.com/api/lounge/bc/bind?AID=96&CI=0&RID=rpc&SID=4C1FDC6522CC404&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=t1_fQf6Or59EhI08_8GccogBZOc3GGGF&id=38ae77ca-f6d2-475c-9950-1cf6ef9e59b5&loungeIdToken=AGdO5p8klJec6yoxGPMNTShVIwmU8f9eUS7sCFmdjcMnlBCHUHkVD9b1vOLFQq5BJV3C9t76xDZOFSsbqqDqCiln6metr2q8Q_SRAFK3WGOhY3O0-uTCHzU&mdxVersion=2&name=YouTube%20on%20VolumioRA1&obfuscatedGaiaId=&t=1&theme=m&v=2&zx=28ed495666c4 Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] RPC connection established. Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 97) (YouTube Music) Incoming message: 'noop' Dec 15 17:17:05 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 97) (YouTube Music) Not handled: 'noop' Dec 15 17:17:09 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:13 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:17:16+01:00" level=trace msg="received accesspoint ping" Dec 15 17:17:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:17:16+01:00" level=trace msg="received accesspoint pong ack" Dec 15 17:17:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:17:16+01:00" level=trace msg="sent dealer ping" Dec 15 17:17:16 volumiora1 go-librespot[1717]: time="2025-12-15T17:17:16+01:00" level=trace msg="received dealer pong" Dec 15 17:17:17 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:20 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:17:20 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 97) (YouTube) Incoming message: 'noop' Dec 15 17:17:20 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 97) (YouTube) Not handled: 'noop' Dec 15 17:17:21 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:25 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:29 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:30 volumiora1 volumio[1326]: verbose: ----------------------------------- Dec 15 17:17:30 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 98) (YouTube Music) Incoming message: 'noop' Dec 15 17:17:30 volumiora1 volumio[1326]: verbose: [yt-cast-receiver] (AID: 98) (YouTube Music) Not handled: 'noop' Dec 15 17:17:33 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Dec 15 17:17:35 volumiora1 volumio[1326]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Dec 15 17:17:35 volumiora1 volumio[1326]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Dec 15 17:17:35 volumiora1 volumio[1326]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 17:17:35 volumiora1 volumio[1326]: TypeError: Cannot read properties of undefined (reading 'then') Dec 15 17:17:35 volumiora1 volumio[1326]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Dec 15 17:17:35 volumiora1 volumio[1326]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Dec 15 17:17:35 volumiora1 volumio[1326]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Dec 15 17:17:35 volumiora1 volumio[1326]: at Socket.emit (node:events:514:28) Dec 15 17:17:35 volumiora1 volumio[1326]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 15 17:17:35 volumiora1 volumio[1326]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 15 17:17:35 volumiora1 volumio[1326]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 17:17:35 volumiora1 sudo[7704]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 17:16' Dec 15 17:17:35 volumiora1 sudo[7704]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"