Apr 14 19:20:30 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:30 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:30 volumio volumio[1135]: info: Prefetching next song Apr 14 19:20:30 volumio volumio[1135]: info: [youtube2] Obtained PO token for video #EUEUZDV-in0: MlsVqFWN_OafCBXsTMzv_dshkP0gl1b4CALpNtNPZo82CuvjCSUzGDJQsDWNw9Yole0IFC_V-GKQqMPfgkX1c0gRNk-YgX83DR1BdOC0SZMkqB5WyVVbwhr8uoBp Apr 14 19:20:31 volumio volumio[1135]: info: [youtube2] Obtained PO token for video #EUEUZDV-in0: Mlv9hOa60PtjOv3A__vD4CcTeNGToHrl9DABGmB4SpLKOAPPuhIfBc5iWBk-9Po1ad_gOJzi1H9smivzMXLZbrQj3mMrtlMq8S-pWFODZY4hjy5y_61N7unDK1mF Apr 14 19:20:31 volumio volumio[1135]: warn: [youtube2] Error getting playback info with TV client. The playability status of the target is: { Apr 14 19:20:31 volumio volumio[1135]: "status": "LOGIN_REQUIRED", Apr 14 19:20:31 volumio volumio[1135]: "reason": "Đăng nhập để xác nhận bạn không phải là robot", Apr 14 19:20:31 volumio volumio[1135]: "embeddable": false, Apr 14 19:20:31 volumio volumio[1135]: "audio_only_playability": null, Apr 14 19:20:31 volumio volumio[1135]: "error_screen": { Apr 14 19:20:31 volumio volumio[1135]: "type": "PlayerErrorCommand", Apr 14 19:20:31 volumio volumio[1135]: "command": { Apr 14 19:20:31 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwiDoNyAqu2TAxWusukFHeAcEN_KAQRg8s9w", Apr 14 19:20:31 volumio volumio[1135]: "authRequiredCommand": { Apr 14 19:20:31 volumio volumio[1135]: "type": "NavigationEndpoint", Apr 14 19:20:31 volumio volumio[1135]: "name": "dismissalCommand", Apr 14 19:20:31 volumio volumio[1135]: "payload": { Apr 14 19:20:31 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwiDoNyAqu2TAxWusukFHeAcEN_KAQRg8s9w", Apr 14 19:20:31 volumio volumio[1135]: "commandExecutorCommand": { Apr 14 19:20:31 volumio volumio[1135]: "commands": [ Apr 14 19:20:31 volumio volumio[1135]: { Apr 14 19:20:31 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwiDoNyAqu2TAxWusukFHeAcEN_KAQRg8s9w", Apr 14 19:20:31 volumio volumio[1135]: "signalAction": { Apr 14 19:20:31 volumio volumio[1135]: "signal": "HISTORY_BACK" Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: }, Apr 14 19:20:31 volumio volumio[1135]: { Apr 14 19:20:31 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwiDoNyAqu2TAxWusukFHeAcEN_KAQRg8s9w", Apr 14 19:20:31 volumio volumio[1135]: "signalAction": { Apr 14 19:20:31 volumio volumio[1135]: "signal": "CLOSE_POPUP" Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: ] Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: }, Apr 14 19:20:31 volumio volumio[1135]: "metadata": {} Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: } Apr 14 19:20:31 volumio volumio[1135]: error: [youtube2] Error in VideoModel.getPlaybackInfo(EUEUZDV-in0): Streaming data not available Error: Streaming data not available Apr 14 19:20:31 volumio volumio[1135]: at Object.chooseFormat (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:2362:11) Apr 14 19:20:31 volumio volumio[1135]: at _VideoInfo.chooseFormat (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:31088:32) Apr 14 19:20:31 volumio volumio[1135]: at VideoModel._VideoModel_chooseFormat (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:253:31) Apr 14 19:20:31 volumio volumio[1135]: at VideoModel._VideoModel_doGetPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:186:122) Apr 14 19:20:31 volumio volumio[1135]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Apr 14 19:20:31 volumio volumio[1135]: at async VideoModel._VideoModel_doGetPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:152:20) Apr 14 19:20:31 volumio volumio[1135]: at async PlayController.getPlaybackInfoFromUri (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:185:19) Apr 14 19:20:31 volumio volumio[1135]: at async PlayController.prefetch (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:253:53) Apr 14 19:20:31 volumio volumio[1135]: error: [youtube2] Error in VideoModel.getPlaybackInfo(EUEUZDV-in0): Streaming data not available Error: Streaming data not available Apr 14 19:20:31 volumio volumio[1135]: at Object.chooseFormat (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:2362:11) Apr 14 19:20:31 volumio volumio[1135]: at _VideoInfo.chooseFormat (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:31088:32) Apr 14 19:20:31 volumio volumio[1135]: at VideoModel._VideoModel_chooseFormat (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:253:31) Apr 14 19:20:31 volumio volumio[1135]: at VideoModel._VideoModel_doGetPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:186:122) Apr 14 19:20:31 volumio volumio[1135]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Apr 14 19:20:31 volumio volumio[1135]: at async VideoModel._VideoModel_doGetPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:152:20) Apr 14 19:20:31 volumio volumio[1135]: at async PlayController.getPlaybackInfoFromUri (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:185:19) Apr 14 19:20:31 volumio volumio[1135]: at async PlayController.prefetch (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:253:53) Apr 14 19:20:31 volumio volumio[1135]: error: [youtube2-play] Prefetch failed: Error: Streaming data not available Apr 14 19:20:35 volumio volumio[1135]: info: Apr 14 19:20:35 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:35 volumio volumio[1135]: info: Apr 14 19:20:35 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:35 volumio volumio[1135]: info: Apr 14 19:20:35 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:35 volumio volumio[1135]: info: sendMpdCommand status took 3 milliseconds Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:35 volumio volumio[1135]: 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} Apr 14 19:20:35 volumio volumio[1135]: verbose: CURRENT POSITION 0 Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::syncState stateService stop Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::play index undefined Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::startPlaybackTimer Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22EUEUZDV-in0%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A1%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22C%C3%B3%20Ch%C3%A0ng%20Trai%20Vi%E1%BA%BFt%20L%C3%AAn%20C%C3%A2y%20-%20Phan%20M%E1%BA%A1nh%20Qu%E1%BB%B3nh%20%7C%20AUDIO%20LYRIC%20OFFICIAL%22%2C%22artist%22%3A%22Phan%20M%E1%BA%A1nh%20Qu%E1%BB%B3nh%20Official%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FEUEUZDV-in0%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLBKQXktzwADfsoku8OK9qLbQRPyog%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22EUEUZDV-in0%22%2C%22playlistId%22%3A%22RDEMAJA8zeMVk9uGI_d3SjFEyQ%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A1%7D%7D%7D Apr 14 19:20:35 volumio volumio[1135]: info: ------------------------------ 27ms Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:35 volumio volumio[1135]: info: sendMpdCommand status took 35 milliseconds Apr 14 19:20:35 volumio volumio[1135]: info: sendMpdCommand status took 35 milliseconds Apr 14 19:20:35 volumio volumio[1135]: info: sendMpdCommand status took 34 milliseconds Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:35 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current youtube2 Received mpd Apr 14 19:20:35 volumio volumio[1135]: info: [youtube2] (AutoplayManager) MPD 'stop' event received Apr 14 19:20:35 volumio volumio[1135]: info: [youtube2] (AutoplayManager) Check if autoplay needed Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: [youtube2] (AutoplayManager) Autoplay not configured or there is no previous played "youtube2" track Apr 14 19:20:35 volumio volumio[1135]: info: [youtube2] (AutoplayManager) Removed mpdStateListener Apr 14 19:20:35 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:35 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:35 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:35 volumio volumio[1135]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current youtube2 Received mpd Apr 14 19:20:35 volumio volumio[1135]: info: ------------------------------ 55ms Apr 14 19:20:35 volumio volumio[1135]: info: ------------------------------ 53ms Apr 14 19:20:35 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:35 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:35 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:35 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:35 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] Obtained PO token for video #EUEUZDV-in0: MlvkXEqp7KEKduQYU-j_uk5fYQk_s0a_nXwYwsxrdsijdBoXFgEjX6cuQcGS58ZvAJP54DDx6CUF1jIrnWHlNN1vx7uHpW9wmGOwgP-QWdRKSoW9noxkAjG42P3b Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] Obtained PO token for video #EUEUZDV-in0: MluHNdQAN2MUc4dxzUEkeFBaAmChGp19g3l7q1LCrQq9cXl-iKj4nbkrIqgMTh2tHpaaia5YM-cb01FCA8g-9sNqpNIZDLSyhmbT6WE5ghaCDvrySMbAuXUEQun_ Apr 14 19:20:36 volumio volumio[1135]: warn: [youtube2] Error getting playback info with TV client. The playability status of the target is: { Apr 14 19:20:36 volumio volumio[1135]: "status": "LOGIN_REQUIRED", Apr 14 19:20:36 volumio volumio[1135]: "reason": "Đăng nhập để xác nhận bạn không phải là robot", Apr 14 19:20:36 volumio volumio[1135]: "embeddable": false, Apr 14 19:20:36 volumio volumio[1135]: "audio_only_playability": null, Apr 14 19:20:36 volumio volumio[1135]: "error_screen": { Apr 14 19:20:36 volumio volumio[1135]: "type": "PlayerErrorCommand", Apr 14 19:20:36 volumio volumio[1135]: "command": { Apr 14 19:20:36 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwil25KDqu2TAxUcRvUFHdrvBWvKAQRg8s9w", Apr 14 19:20:36 volumio volumio[1135]: "authRequiredCommand": { Apr 14 19:20:36 volumio volumio[1135]: "type": "NavigationEndpoint", Apr 14 19:20:36 volumio volumio[1135]: "name": "dismissalCommand", Apr 14 19:20:36 volumio volumio[1135]: "payload": { Apr 14 19:20:36 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwil25KDqu2TAxUcRvUFHdrvBWvKAQRg8s9w", Apr 14 19:20:36 volumio volumio[1135]: "commandExecutorCommand": { Apr 14 19:20:36 volumio volumio[1135]: "commands": [ Apr 14 19:20:36 volumio volumio[1135]: { Apr 14 19:20:36 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwil25KDqu2TAxUcRvUFHdrvBWvKAQRg8s9w", Apr 14 19:20:36 volumio volumio[1135]: "signalAction": { Apr 14 19:20:36 volumio volumio[1135]: "signal": "HISTORY_BACK" Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: }, Apr 14 19:20:36 volumio volumio[1135]: { Apr 14 19:20:36 volumio volumio[1135]: "clickTrackingParams": "CAAQu2kiEwil25KDqu2TAxUcRvUFHdrvBWvKAQRg8s9w", Apr 14 19:20:36 volumio volumio[1135]: "signalAction": { Apr 14 19:20:36 volumio volumio[1135]: "signal": "CLOSE_POPUP" Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: ] Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: }, Apr 14 19:20:36 volumio volumio[1135]: "metadata": {} Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: } Apr 14 19:20:36 volumio volumio[1135]: warn: [youtube2] Got error in VideoModel.getPlaybackInfo(EUEUZDV-in0): Streaming data not available Apr 14 19:20:36 volumio volumio[1135]: warn: [youtube2] Going to retry with 'MWEB' client Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] Obtained PO token for video #EUEUZDV-in0: MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] Got stream with MWEB client Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] VideoModel.getPlaybackInfo(EUEUZDV-in0): validating stream URL "https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA"... Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] VideoModel.getPlaybackInfo(EUEUZDV-in0): stream validated in 0.078s. Apr 14 19:20:36 volumio volumio[1135]: info: [youtube2] (AutoplayManager) Enabled Apr 14 19:20:36 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand stop Apr 14 19:20:36 volumio volumio[1135]: info: sendMpdCommand stop took 2 milliseconds Apr 14 19:20:36 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand clear Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: sendMpdCommand clear took 2 milliseconds Apr 14 19:20:36 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand addid "https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube" Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: error: updateQueue error: null Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 5ms Apr 14 19:20:36 volumio volumio[1135]: info: sendMpdCommand addid "https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube" took 4 milliseconds Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 3ms Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 2ms Apr 14 19:20:36 volumio volumio[1135]: verbose: MPD COMMAND [object Object] Apr 14 19:20:36 volumio volumio[1135]: verbose: MPD COMMAND [object Object] Apr 14 19:20:36 volumio volumio[1135]: verbose: MPD COMMAND [object Object] Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 5ms Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 3ms Apr 14 19:20:36 volumio volumio[1135]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 14 19:20:36 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand play Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 4ms Apr 14 19:20:36 volumio volumio[1135]: info: Apr 14 19:20:36 volumio volumio[1135]: ---------------------------- MPD announces system playlist update Apr 14 19:20:36 volumio volumio[1135]: info: Ignoring MPD Status Update Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 4ms Apr 14 19:20:36 volumio volumio[1135]: info: sendMpdCommand play took 3 milliseconds Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 2ms Apr 14 19:20:36 volumio volumio[1135]: info: ------------------------------ 6ms Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 140 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 143 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 143 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 4 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 4 milliseconds Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus stop Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 151ms Apr 14 19:20:37 volumio volumio[1135]: info: Apr 14 19:20:37 volumio volumio[1135]: ---------------------------- MPD announces state update: player Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::getState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand status Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 10 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 7 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 8 milliseconds Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":489,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:37 volumio volumio[1135]: info: Received an update from plugin. extracting info from payload Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: [youtube2] (AutoplayManager) Added mpdStateListener Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":992,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:37 volumio volumio[1135]: info: Received an update from plugin. extracting info from payload Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":992,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:37 volumio volumio[1135]: info: Received an update from plugin. extracting info from payload Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 209ms Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 209ms Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 70ms Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand status took 62 milliseconds Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 59 milliseconds Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseState Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":992,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:37 volumio volumio[1135]: info: Received an update from plugin. extracting info from payload Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 87ms Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: info: sendMpdCommand playlistinfo took 70 milliseconds Apr 14 19:20:37 volumio volumio[1135]: verbose: ControllerMpd::parseTrackInfo Apr 14 19:20:37 volumio volumio[1135]: info: ControllerMpd::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::servicePushState Apr 14 19:20:37 volumio volumio[1135]: info: CorePlayQueue::getTrack 1 Apr 14 19:20:37 volumio volumio[1135]: verbose: STATE SERVICE {"status":"play","position":0,"seek":992,"duration":310,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Có Chàng Trai Viết Lên Cây - Phan Mạnh Quỳnh | AUDIO LYRIC OFFICIAL","artist":"Phan Mạnh Quỳnh Official","album":"YouTube","uri":"https://rr1---sn-8qj-i5ods.googlevideo.com/videoplayback?expire=1776190836&ei=FDHeaZGBHr3D1d8Pz7vToAI&ip=14.175.85.105&id=o-APQBukL29pfwU51wkDTJWDvyBVWBK7CxosZwKMzmSgPv&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=719&met=1776169236%2C&mh=3x&mm=31%2C29&mn=sn-8qj-i5ods%2Csn-8qj-i5ok6&ms=au%2Crdu&mv=m&mvi=1&pl=23&rms=au%2Cau&initcwndbps=2693750&bui=AUUZDGJq1WYjXKymZ7040opUgOH5oyKh4Zj1MoucHpnfKuwiHVXZSDCGyE-Xw_ZtKyQOZ_Grl0TA8T64&spc=jlWavWGpEOrwxUSBMgWolPS2UYu1P2yTJ6VzoyiGQ8KkdmkqQuQYelFhx8bhjuPV_tP4SQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=F3fl69AmoEqbe_5aSMfIdPIU&rqh=1&gir=yes&clen=5231811&dur=310.021&lmt=1751192901673366&mt=1776168801&fvip=3&keepalive=yes&fexp=51565115%2C51565682%2C51869322&c=MWEB&sefc=1&txp=4532534&n=4Hu0KsfmRmi9bA&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=APaTxxMwRgIhAIAuc6Wn8OtHh32vOFuw5sZS3TEIzGK47UxqltOrec1BAiEAyADqBonenm9ynT6Jzt8yuJZDXSlunYMv6yQDQn2OejY%3D&sig=AHEqNM4wRAIgWWpXi3SBFJ-9WxyY-oVHSTeQQ_l7YMl7Q8zLAH244ekCIED9z6WIbyKIEsN6SAcEAAonH3uLujFOM3Bcp5TMVAPd&cver=2.20260205.04.01&pot=MlufI7vV9POKAZ9nopTn6M4oGnbOz17tHQtjvT0XbpojA2Fo5307DSdZOr5jm949gOSCn8GN8HeFoUlUbB39Zl0YvMR22XciGBTL_w7sQYa9L389NL4cT6L9LdYA&t.YouTube","trackType":"YouTube"} Apr 14 19:20:37 volumio volumio[1135]: verbose: CURRENT POSITION 1 Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState stateService play Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::syncState currentStatus play Apr 14 19:20:37 volumio volumio[1135]: info: Received an update from plugin. extracting info from payload Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreStateMachine::pushState Apr 14 19:20:37 volumio volumio[1135]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:37 volumio volumio[1135]: info: ------------------------------ 149ms Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:37 volumio volumio[1135]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Apr 14 19:20:39 volumio go-librespot[1646]: time="2026-04-14T19:20:39+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Apr 14 19:20:40 volumio go-librespot[1646]: time="2026-04-14T19:20:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:20:40 volumio go-librespot[1646]: time="2026-04-14T19:20:40+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:40 volumio go-librespot[1646]: time="2026-04-14T19:20:40+07:00" level=debug msg="completed challenge" Apr 14 19:20:40 volumio go-librespot[1646]: time="2026-04-14T19:20:40+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:41 volumio go-librespot[1646]: time="2026-04-14T19:20:41+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:20:41 volumio go-librespot[1646]: time="2026-04-14T19:20:41+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:41 volumio go-librespot[1646]: time="2026-04-14T19:20:41+07:00" level=debug msg="completed challenge" Apr 14 19:20:41 volumio go-librespot[1646]: time="2026-04-14T19:20:41+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:42 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Apr 14 19:20:42 volumio go-librespot[1646]: time="2026-04-14T19:20:42+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 19:20:42 volumio go-librespot[1646]: time="2026-04-14T19:20:42+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:42 volumio go-librespot[1646]: time="2026-04-14T19:20:42+07:00" level=debug msg="completed challenge" Apr 14 19:20:43 volumio go-librespot[1646]: time="2026-04-14T19:20:43+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:43 volumio go-librespot[1646]: time="2026-04-14T19:20:43+07:00" level=debug msg="connected to ap-gew1.spotify.com:80" Apr 14 19:20:44 volumio go-librespot[1646]: time="2026-04-14T19:20:44+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:44 volumio go-librespot[1646]: time="2026-04-14T19:20:44+07:00" level=debug msg="completed challenge" Apr 14 19:20:44 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Apr 14 19:20:44 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Apr 14 19:20:44 volumio go-librespot[1646]: time="2026-04-14T19:20:44+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:44 volumio go-librespot[1646]: time="2026-04-14T19:20:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:20:44 volumio volumio[1135]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Apr 14 19:20:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:20:44 volumio volumio[1135]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:20:44 volumio volumio[1135]: Error: socket hang up Apr 14 19:20:44 volumio volumio[1135]: at connResetException (node:internal/errors:720:14) Apr 14 19:20:44 volumio volumio[1135]: at Socket.socketOnEnd (node:_http_client:519:23) Apr 14 19:20:44 volumio volumio[1135]: at Socket.emit (node:events:526:35) Apr 14 19:20:44 volumio volumio[1135]: at endReadableNT (node:internal/streams/readable:1376:12) Apr 14 19:20:44 volumio volumio[1135]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Apr 14 19:20:44 volumio volumio[1135]: code: 'ECONNRESET', Apr 14 19:20:44 volumio volumio[1135]: response: undefined Apr 14 19:20:44 volumio volumio[1135]: } Apr 14 19:20:44 volumio volumio[1135]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:20:44 volumio sudo[4287]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:19' Apr 14 19:20:44 volumio sudo[4287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:44 volumio sudo[4287]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:46 volumio volumio5-onboarding[1406]: time=2026-04-14T19:20:46.026+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Apr 14 19:20:46 volumio volumio-remote-updater[827]: [2026-04-14 19:20:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 14 19:20:46 volumio volumio-remote-updater[827]: [2026-04-14 19:20:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 14 19:20:46 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:20:46 volumio volumio5-onboarding[1406]: time=2026-04-14T19:20:46.028+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:20:46 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 14 19:20:46 volumio systemd[1]: volumio.service: Consumed 3min 38.062s CPU time. Apr 14 19:20:46 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:20:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:20:46 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Apr 14 19:20:46 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Apr 14 19:20:46 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Apr 14 19:20:46 volumio systemd[1]: volumio.service: Consumed 3min 38.062s CPU time. Apr 14 19:20:46 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Apr 14 19:20:46 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Apr 14 19:20:47 volumio volumio5-onboarding[1406]: time=2026-04-14T19:20:47.031+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Apr 14 19:20:47 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:47 volumio volumio[4332]: info: ----- Volumio3 ---- Apr 14 19:20:47 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:47 volumio volumio[4332]: info: ----- System startup ---- Apr 14 19:20:47 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 14 19:20:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:20:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:20:47 volumio go-librespot[4354]: go-librespot daemon starting... Apr 14 19:20:47 volumio go-librespot[4355]: time="2026-04-14T19:20:47+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:20:47 volumio go-librespot[4355]: time="2026-04-14T19:20:47+07:00" level=debug msg="app state loaded" Apr 14 19:20:47 volumio go-librespot[4355]: time="2026-04-14T19:20:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:20:47 volumio volumio[4332]: info: MYVOLUMIO Environment detected Apr 14 19:20:47 volumio volumio[4332]: info: Plugin folders cleanup Apr 14 19:20:47 volumio volumio[4332]: info: Scanning into folder /volumio/app/plugins/ Apr 14 19:20:47 volumio volumio[4332]: info: Scanning category audio_interface Apr 14 19:20:47 volumio volumio[4332]: info: Scanning category miscellanea Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category music_service Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category plugins.json Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category system_controller Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category user_interface Apr 14 19:20:48 volumio volumio[4332]: info: Scanning into folder /data/plugins/ Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category music_service Apr 14 19:20:48 volumio volumio[4332]: info: Scanning category system_hardware Apr 14 19:20:48 volumio volumio[4332]: info: Plugin folders cleanup completed Apr 14 19:20:48 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:48 volumio volumio[4332]: info: ----- Core plugins startup ---- Apr 14 19:20:48 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugins from folder /volumio/app/plugins/ Apr 14 19:20:48 volumio volumio[4332]: info: Adding plugin upnp to MyMusic Plugins Apr 14 19:20:48 volumio volumio[4332]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 14 19:20:48 volumio volumio[4332]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugins from folder /data/plugins/ Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=info msg="zeroconf server listening on port 39867" Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "system"... Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "appearance"... Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="obtained new client token: AAAv0yngJPk/MiRiw+mFilpT+/m0ZzLENv/8AStnZ1NBKSRTvjiPcZQMuhoKTgE17CBdDZWXfE4VwgtdDl5GDps/kpOe6+60V/38KowX3upta/ni9EK7XTJsBCmRT8BGD9beqVmHwSziiQnz1Xfv5KrxF/s1NxZkv49hqXwP5u2JWD1MjjGfhqlfyxrqDS0kQsnDuCAb5wNs6SBvC1PWMuiTUmZgAK4i8hbvwxO69ReiAZJmsc5F0w==" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=debug msg="completed challenge" Apr 14 19:20:48 volumio go-librespot[4355]: time="2026-04-14T19:20:48+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "network"... Apr 14 19:20:48 volumio volumio[4332]: info: Refreshing Cached IP Addresses Apr 14 19:20:48 volumio sudo[4372]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:20:48 volumio sudo[4374]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:20:48 volumio sudo[4374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:48 volumio sudo[4372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "services"... Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "volumio5onboarding"... Apr 14 19:20:48 volumio sudo[4372]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:48 volumio sudo[4384]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "alsa_controller"... Apr 14 19:20:48 volumio sudo[4384]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:48 volumio sudo[4374]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:48 volumio sudo[4384]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:48 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "wizard"... Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "networkfs"... Apr 14 19:20:48 volumio volumio[4332]: info: Starting Udev Watcher for removable devices Apr 14 19:20:48 volumio volumio[4332]: info: Ignoring mount for partition: boot Apr 14 19:20:48 volumio volumio[4332]: info: Ignoring mount for partition: volumio Apr 14 19:20:48 volumio volumio[4332]: info: Ignoring mount for partition: volumio_data Apr 14 19:20:48 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "volumio_command_line_client"... Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "upnp"... Apr 14 19:20:48 volumio volumio[4332]: info: [1776169248940] Starting Upmpd Daemon Apr 14 19:20:48 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "my_music"... Apr 14 19:20:48 volumio volumio[4332]: info: Loading plugin "mpd"... Apr 14 19:20:49 volumio volumio[4332]: info: Loading plugin "upnp_browser"... Apr 14 19:20:49 volumio go-librespot[4355]: time="2026-04-14T19:20:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:20:49 volumio go-librespot[4355]: time="2026-04-14T19:20:49+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:49 volumio go-librespot[4355]: time="2026-04-14T19:20:49+07:00" level=debug msg="completed challenge" Apr 14 19:20:49 volumio go-librespot[4355]: time="2026-04-14T19:20:49+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:50 volumio volumio[4332]: info: Starting UPNP Browser Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "alarm-clock"... Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "airplay_emulation"... Apr 14 19:20:50 volumio volumio[4332]: info: Starting Shairport Sync Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "last_100"... Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "webradio"... Apr 14 19:20:50 volumio go-librespot[4355]: time="2026-04-14T19:20:50+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "i2s_dacs"... Apr 14 19:20:50 volumio volumio[4332]: info: I2S DAC not set, start Auto-detection Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "volumiodiscovery"... Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** For more information see Apr 14 19:20:50 volumio node[4332]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:20:50 volumio volumio[4332]: *** WARNING *** For more information see Apr 14 19:20:50 volumio node[4332]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:20:50 volumio node[4332]: *** WARNING *** For more information see Apr 14 19:20:50 volumio node[4332]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 14 19:20:50 volumio node[4332]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 14 19:20:50 volumio node[4332]: *** WARNING *** For more information see Apr 14 19:20:50 volumio volumio[4332]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 14 19:20:50 volumio volumio[4332]: info: Discovery: Started advertising with name: Volumio Apr 14 19:20:50 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "mixcloud"... Apr 14 19:20:50 volumio go-librespot[4355]: time="2026-04-14T19:20:50+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:50 volumio go-librespot[4355]: time="2026-04-14T19:20:50+07:00" level=debug msg="completed challenge" Apr 14 19:20:50 volumio volumio[4332]: info: Plugin soundcloud is not enabled Apr 14 19:20:50 volumio volumio[4332]: info: Loading plugin "spop"... Apr 14 19:20:50 volumio go-librespot[4355]: time="2026-04-14T19:20:50+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:51 volumio volumio-remote-updater[827]: [2026-04-14 19:20:51] [connect] Successful connection Apr 14 19:20:51 volumio volumio[4332]: info: Loading plugin "youtube2"... Apr 14 19:20:51 volumio go-librespot[4355]: time="2026-04-14T19:20:51+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 19:20:51 volumio go-librespot[4355]: time="2026-04-14T19:20:51+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:51 volumio go-librespot[4355]: time="2026-04-14T19:20:51+07:00" level=debug msg="completed challenge" Apr 14 19:20:51 volumio volumio[4332]: info: Loading plugin "ytcr"... Apr 14 19:20:52 volumio go-librespot[4355]: time="2026-04-14T19:20:52+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "outputs"... Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "albumart"... Apr 14 19:20:52 volumio volumio[4332]: info: Plugin example_plugin is not enabled Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "inputs"... Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "updater_comm"... Apr 14 19:20:52 volumio go-librespot[4355]: time="2026-04-14T19:20:52+07:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Apr 14 19:20:52 volumio volumio[4332]: info: Plugin mpdemulation is not enabled Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "rest_api"... Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "websocket"... Apr 14 19:20:52 volumio volumio[4332]: info: Starting Socket.io Server version 1.7.4 Apr 14 19:20:52 volumio volumio[4415]: Forking 3 albumart workers Apr 14 19:20:52 volumio volumio[4332]: info: Loading plugin "storage_manager"... Apr 14 19:20:52 volumio go-librespot[4355]: time="2026-04-14T19:20:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:20:53 volumio volumio[4332]: info: Loading i18n strings for locale vi Apr 14 19:20:53 volumio volumio[4332]: Updating browse sources language Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=debug msg="completed challenge" Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::initPlayerControls Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: Express server listening on port 3000 Apr 14 19:20:53 volumio volumio[4332]: [Metrics] WebUI: 6s 67.91ms Apr 14 19:20:53 volumio volumio[4332]: info: Setting Device type: x86 Apr 14 19:20:53 volumio volumio[4332]: info: CoreStateMachine::resetVolumioState Apr 14 19:20:53 volumio volumio[4332]: info: CoreStateMachine::getcurrentVolume Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Apr 14 19:20:53 volumio volumio[4332]: info: Completed loading Core Plugins Apr 14 19:20:53 volumio volumio[4332]: info: Preparing to generate the ALSA configuration file Apr 14 19:20:53 volumio volumio[4332]: info: Volumio Network Manager: Network status updated: 1 Apr 14 19:20:53 volumio volumio[4332]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 14 19:20:53 volumio volumio[4332]: wlan0 Interface doesn't support scanning. Apr 14 19:20:53 volumio volumio[4332]: info: Cannot use regular scanning, forcing with ap-force Apr 14 19:20:53 volumio sudo[4460]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 14 19:20:53 volumio sudo[4460]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio sudo[4460]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:53 volumio volumio[4332]: command failed: No such device (-19) Apr 14 19:20:53 volumio volumio[4332]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 14 19:20:53 volumio volumio[4332]: command failed: No such device (-19) Apr 14 19:20:53 volumio volumio[4332]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Apr 14 19:20:53 volumio volumio[4425]: Starting albumart workers Apr 14 19:20:53 volumio volumio[4332]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 1 Apr 14 19:20:53 volumio volumio[4332]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:20:53 volumio volumio[4332]: info: CoreStateMachine::pushState Apr 14 19:20:53 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:53 volumio volumio[4332]: info: CoreStateMachine::updateTrackBlock Apr 14 19:20:53 volumio volumio[4332]: info: CorePlayQueue::getTrackBlock Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioRetrievevolume Apr 14 19:20:53 volumio volumio[4427]: Starting albumart workers Apr 14 19:20:53 volumio volumio-remote-updater[827]: [2026-04-14 19:20:53] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1776169251 101 Apr 14 19:20:53 volumio volumio[4332]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 1 Apr 14 19:20:53 volumio volumio[4426]: Starting albumart workers Apr 14 19:20:53 volumio volumio[4332]: info: Reloading queue from file Apr 14 19:20:53 volumio volumio[4332]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 19:20:53 volumio volumio[4332]: info: Asound.conf file unchanged, so no further update is needed Apr 14 19:20:53 volumio volumio[4332]: info: Output device has changed, restarting MPD Apr 14 19:20:53 volumio volumio[4332]: info: Output device has changed, restarting Shairport Sync Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:53 volumio sudo[4474]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:20:53 volumio sudo[4474]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio sudo[4470]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:20:53 volumio sudo[4470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio volumio[4332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:20:53 volumio volumio[4332]: info: ___________ START PLUGINS ___________ Apr 14 19:20:53 volumio sudo[4470]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:53 volumio volumio[4332]: info: ControllerMpd::onStart: Initializing MPD Apr 14 19:20:53 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 14 19:20:53 volumio volumio[4332]: info: Creating MPD Configuration file Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 14 19:20:53 volumio sudo[4480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Apr 14 19:20:53 volumio sudo[4480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:53 volumio volumio[4332]: info: [1776169253797] CoreMusicLibrary::Adding element Máy chủ Media Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:53 volumio sudo[4484]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 14 19:20:53 volumio volumio[4332]: info: UPNP Browser: Client initialized successfully Apr 14 19:20:53 volumio sudo[4484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=debug msg="completed challenge" Apr 14 19:20:53 volumio sudo[4480]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:53 volumio sudo[4482]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 14 19:20:53 volumio sudo[4482]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:53 volumio sudo[4482]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:53 volumio volumio[4332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:53 volumio go-librespot[4355]: time="2026-04-14T19:20:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:20:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:20:53 volumio volumio[4332]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:53 volumio volumio[4332]: info: [1776169253969] CoreMusicLibrary::Adding element Last_100 Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:53 volumio volumio[4332]: info: [1776169253973] CoreMusicLibrary::Adding element Webradio Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:53 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:20:53 volumio volumio[4332]: info: Initializing BBC Radios Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 14 19:20:54 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 14 19:20:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 14 19:20:54 volumio systemd[1]: mpd.service: Consumed 19.145s CPU time. Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 14 19:20:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 14 19:20:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:54 volumio volumio[4332]: info: [1776169254071] CoreMusicLibrary::Adding element Mixcloud Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:54 volumio volumio[4332]: Cannot find translation for source Mixcloud Apr 14 19:20:54 volumio volumio[4332]: info: Creating Spotify config file Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 14 19:20:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 14 19:20:54 volumio sudo[4512]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 14 19:20:54 volumio sudo[4512]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 14 19:20:54 volumio sudo[4512]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:54 volumio volumio[4332]: info: [1776169254333] CoreMusicLibrary::Adding element YouTube2 Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:54 volumio volumio[4332]: Cannot find translation for source Mixcloud Apr 14 19:20:54 volumio volumio[4332]: Cannot find translation for source YouTube2 Apr 14 19:20:54 volumio volumio[4332]: info: [ytcr] Data store TTL expired - clearing it... Apr 14 19:20:54 volumio volumio[4332]: info: Volumio Calling Home Apr 14 19:20:54 volumio volumio[4332]: info: CoreStateMachine::setRepeat null single undefined Apr 14 19:20:54 volumio volumio[4332]: info: CoreStateMachine::pushState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:54 volumio volumio[4332]: info: CoreStateMachine::setRandom false Apr 14 19:20:54 volumio volumio[4332]: info: CoreStateMachine::pushState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:54 volumio volumio[4332]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Apr 14 19:20:54 volumio volumio[4332]: info: VolumeController:: Volume=30 Mute =false Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioGetState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio volumio[4332]: info: CoreStateMachine::pushState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioPushState Apr 14 19:20:54 volumio volumio[4332]: info: MPD Permissions set Apr 14 19:20:54 volumio volumio[4332]: info: MPD Permissions set Apr 14 19:20:54 volumio volumio[4332]: info: Spotify config file written Apr 14 19:20:54 volumio sudo[4539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 14 19:20:54 volumio sudo[4539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:54 volumio volumio[4332]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio go-librespot[4546]: go-librespot daemon starting... Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio sudo[4539]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:54 volumio go-librespot[4550]: time="2026-04-14T19:20:54+07:00" level=info msg="running go-librespot 0.7.1" Apr 14 19:20:54 volumio go-librespot[4550]: time="2026-04-14T19:20:54+07:00" level=debug msg="app state loaded" Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Apr 14 19:20:54 volumio go-librespot[4550]: time="2026-04-14T19:20:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 14 19:20:54 volumio volumio[4332]: info: No need to fix Spotify hosts Apr 14 19:20:54 volumio volumio[4332]: info: Discovery: adding aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:20:54 volumio volumio[4332]: info: Discovery: Found device Volumio Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioGetState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio volumio[4332]: info: Starting Shairport Sync Apr 14 19:20:54 volumio volumio[4332]: info: Starting Shairport Sync Apr 14 19:20:54 volumio volumio[4332]: info: Starting Shairport Sync Apr 14 19:20:54 volumio sudo[4567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:20:54 volumio sudo[4567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:54 volumio volumio[4332]: info: Discovery: this is already registered, aa82207a-60f0-4c82-a831-795ebb2415c3 Apr 14 19:20:54 volumio volumio[4332]: info: Discovery: Found device Volumio Apr 14 19:20:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:20:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:20:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:20:54 volumio systemd[1]: shairport-sync.service: Consumed 14.142s CPU time. Apr 14 19:20:54 volumio volumio[4332]: info: CoreCommandRouter::volumioGetState Apr 14 19:20:54 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:54 volumio sudo[4569]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:20:54 volumio sudo[4569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:54 volumio sudo[4573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 14 19:20:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:20:54 volumio sudo[4573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:54 volumio sudo[4567]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:54 volumio volumio[4332]: info: Volumio called home Apr 14 19:20:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 14 19:20:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 14 19:20:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:20:55 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 14 19:20:55 volumio sudo[4569]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:55 volumio sudo[4573]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=info msg="zeroconf server listening on port 35857" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" Apr 14 19:20:55 volumio volumio[4332]: info: Shairport-Sync Started Apr 14 19:20:55 volumio volumio[4332]: Error adding Membership: Error: addMembership EINVAL Apr 14 19:20:55 volumio volumio[4332]: info: Shairport-Sync Started Apr 14 19:20:55 volumio volumio[4332]: info: Shairport-Sync Started Apr 14 19:20:55 volumio volumio[4332]: info: CoreCommandRouter::volumioGetState Apr 14 19:20:55 volumio volumio[4332]: info: CorePlayQueue::getTrack 0 Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="obtained new client token: AACWWtbwKG57D2rhdT0VUxdiO4S4Ofpd6Vwnkh7agvrXvAEB0b8/eZKl+1cFYvryJy50jnbJaKGXaXfjABajE1upRCPhRPK2pyN0+7UxDuDJrEdrQTmezQgj9xYB7aKlTO09dFRj+zig8CrjZq/Ll3I9d7mh4yVD05rMoRjOCim5412RJ2F0WzjnhbhwC7jXIdlrNvljD/+h8SMtTLlhIMSRdK5FFbhSlTIi1v3tKTZsLI9hRd6HxkDY" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:20:55 volumio mpd[4531]: 2026-04-14T19:20:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 14 19:20:55 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 14 19:20:55 volumio sudo[4474]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:55 volumio sudo[4484]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=debug msg="completed challenge" Apr 14 19:20:55 volumio volumio[4332]: error: MPD error: The expression evaluated to a falsy value: Apr 14 19:20:55 volumio volumio[4332]: assert.ok(self.idling) Apr 14 19:20:55 volumio volumio[4332]: error: The expression evaluated to a falsy value: Apr 14 19:20:55 volumio volumio[4332]: assert.ok(self.idling) Apr 14 19:20:55 volumio volumio[4332]: info: MPD running with PID4531 Apr 14 19:20:55 volumio volumio[4332]: ,establishing connection Apr 14 19:20:55 volumio volumio[4332]: error: updateQueue error: null Apr 14 19:20:55 volumio volumio[4332]: info: New Spotify access tokenBQBkdcGjIb... Apr 14 19:20:55 volumio volumio[4332]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 14 19:20:55 volumio volumio[4332]: error: updateQueue error: null Apr 14 19:20:55 volumio go-librespot[4550]: time="2026-04-14T19:20:55+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:56 volumio volumio[4332]: SPOTIFY: User informations: {"country":"GB","display_name":"Kenky Cool","email":"kenkycool97@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/42j4swbhr91mth0xx3exmu8s0"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/42j4swbhr91mth0xx3exmu8s0","id":"42j4swbhr91mth0xx3exmu8s0","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=300&width=300&ext=1778753480&hash=AT8-KOYVDV5N6LlcBEJhd_qw","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=704097286671714&height=50&width=50&ext=1778753480&hash=AT-KltT7sc5TFuHT3APbyHTf","width":64}],"product":"free","type":"user","uri":"spotify:user:42j4swbhr91mth0xx3exmu8s0"} Apr 14 19:20:56 volumio volumio[4332]: info: Spotify Successfully logged in Apr 14 19:20:56 volumio volumio[4332]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 14 19:20:56 volumio volumio[4332]: info: [1776169256046] CoreMusicLibrary::Adding element Spotify Apr 14 19:20:56 volumio volumio[4332]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 14 19:20:56 volumio volumio[4332]: Cannot find translation for source Mixcloud Apr 14 19:20:56 volumio volumio[4332]: Cannot find translation for source YouTube2 Apr 14 19:20:56 volumio volumio[4332]: Cannot find translation for source Spotify Apr 14 19:20:56 volumio go-librespot[4550]: time="2026-04-14T19:20:56+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Apr 14 19:20:56 volumio go-librespot[4550]: time="2026-04-14T19:20:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:80" Apr 14 19:20:56 volumio go-librespot[4550]: time="2026-04-14T19:20:56+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:56 volumio go-librespot[4550]: time="2026-04-14T19:20:56+07:00" level=debug msg="completed challenge" Apr 14 19:20:56 volumio go-librespot[4550]: time="2026-04-14T19:20:56+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:57 volumio volumio[4332]: info: [yt-cast-receiver] DIAL server listening on port 8098 Apr 14 19:20:57 volumio volumio[4332]: info: Completed starting Core Plugins Apr 14 19:20:57 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:57 volumio volumio[4332]: info: ----- MyVolumio plugins startup ---- Apr 14 19:20:57 volumio volumio[4332]: info: ------------------------------------------- Apr 14 19:20:57 volumio volumio[4332]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 14 19:20:57 volumio go-librespot[4550]: time="2026-04-14T19:20:57+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Apr 14 19:20:57 volumio go-librespot[4550]: time="2026-04-14T19:20:57+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:57 volumio go-librespot[4550]: time="2026-04-14T19:20:57+07:00" level=debug msg="completed challenge" Apr 14 19:20:57 volumio volumio[4332]: info: go-librespot daemon successfully initialized Apr 14 19:20:57 volumio go-librespot[4550]: time="2026-04-14T19:20:57+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:20:58 volumio go-librespot[4550]: time="2026-04-14T19:20:58+07:00" level=debug msg="connected to ap-gue1.spotify.com:443" Apr 14 19:20:58 volumio sudo[4621]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 14 19:20:58 volumio sudo[4621]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:58 volumio sudo[4621]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:58 volumio sudo[4624]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 14 19:20:59 volumio sudo[4624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:59 volumio sudo[4626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 14 19:20:59 volumio sudo[4626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 14 19:20:59 volumio sudo[4624]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:59 volumio go-librespot[4550]: time="2026-04-14T19:20:59+07:00" level=debug msg="completed keyexchange" Apr 14 19:20:59 volumio go-librespot[4550]: time="2026-04-14T19:20:59+07:00" level=debug msg="completed challenge" Apr 14 19:20:59 volumio sudo[4626]: pam_unix(sudo:session): session closed for user root Apr 14 19:20:59 volumio volumio[4332]: info: Upmpdcli Daemon Started Apr 14 19:20:59 volumio go-librespot[4550]: time="2026-04-14T19:20:59+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="connected to ap-gew4.spotify.com:80" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="completed challenge" Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:00 volumio volumio[4332]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 14 19:21:00 volumio volumio[4332]: info: Initializing connection to go-librespot Websocket Apr 14 19:21:00 volumio go-librespot[4550]: time="2026-04-14T19:21:00+07:00" level=debug msg="new websocket client" Apr 14 19:21:00 volumio volumio[4332]: info: Connection to go-librespot Websocket established Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="completed keyexchange" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=debug msg="completed challenge" Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:01 volumio go-librespot[4550]: time="2026-04-14T19:21:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TravelRestriction " Apr 14 19:21:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 14 19:21:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 14 19:21:01 volumio volumio[4332]: info: Connection to go-librespot Websocket closed Apr 14 19:21:03 volumio volumio[4332]: info: Getting Spotify volume Apr 14 19:21:03 volumio volumio[4332]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:03 volumio volumio[4332]: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 14 19:21:03 volumio volumio[4332]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Apr 14 19:21:03 volumio volumio[4332]: errno: -111, Apr 14 19:21:03 volumio volumio[4332]: code: 'ECONNREFUSED', Apr 14 19:21:03 volumio volumio[4332]: syscall: 'connect', Apr 14 19:21:03 volumio volumio[4332]: address: '127.0.0.1', Apr 14 19:21:03 volumio volumio[4332]: port: 9879, Apr 14 19:21:03 volumio volumio[4332]: response: undefined Apr 14 19:21:03 volumio volumio[4332]: } Apr 14 19:21:03 volumio volumio[4332]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 14 19:21:04 volumio sudo[4651]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-14 19:20' Apr 14 19:21:04 volumio sudo[4651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"