Jan 25 18:31:29 volumio go-librespot[1928]: time="2026-01-25T18:31:29+07:00" level=trace msg="sent dealer ping" Jan 25 18:31:29 volumio go-librespot[1928]: time="2026-01-25T18:31:29+07:00" level=trace msg="received dealer pong" Jan 25 18:31:59 volumio go-librespot[1928]: time="2026-01-25T18:31:59+07:00" level=trace msg="sent dealer ping" Jan 25 18:31:59 volumio go-librespot[1928]: time="2026-01-25T18:31:59+07:00" level=trace msg="received dealer pong" Jan 25 18:31:59 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17:3000 from 192.168.1.15 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:31:59 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:31:59 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:31:59 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:31:59 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 25 18:31:59 volumio sudo[9388]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 25 18:31:59 volumio sudo[9388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9393]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 25 18:31:59 volumio sudo[9393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9400]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 25 18:31:59 volumio sudo[9400]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 25 18:31:59 volumio sudo[9405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9388]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio sudo[9412]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 18:31:59 volumio sudo[9412]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9393]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio sudo[9412]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio sudo[9422]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 18:31:59 volumio sudo[9422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:31:59 volumio sudo[9400]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio sudo[9405]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio sudo[9422]: pam_unix(sudo:session): session closed for user root Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:31:59 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:31:59 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:31:59 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:31:59 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:31:59 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:31:59 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17:3000 from 192.168.1.15 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 18:31:59 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:00 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:00 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:00 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17:3000 from 192.168.1.15 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 18:32:00 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 18:32:01 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 18:32:01 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 18:32:02 volumio sudo[9461]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 18:32:02 volumio sudo[9461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:02 volumio sudo[9461]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:02 volumio sudo[9463]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 18:32:02 volumio sudo[9463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:02 volumio sudo[9463]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:02 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17 from 192.168.1.15 UA: Mozilla/5.0 (Linux; Android 12; M2007J3SG Build/SKQ1.211006.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.193 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 18:32:02 volumio sudo[9470]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 18:32:02 volumio sudo[9470]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:02 volumio sudo[9470]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:02 volumio sudo[9472]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 18:32:02 volumio sudo[9472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:02 volumio sudo[9472]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:02 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17 from 192.168.1.15 UA: Mozilla/5.0 (Linux; Android 12; M2007J3SG Build/SKQ1.211006.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.193 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::volumioGetVisibleSources Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:02 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 25 18:32:02 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:02 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:02 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:02 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:02 volumio volumio[1163]: info: Listing playlists Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 25 18:32:02 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 18:32:03 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 18:32:04 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:04 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:04 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:04 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 18:32:08 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:08 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:08 volumio volumio[1163]: info: Prefetching next song Jan 25 18:32:08 volumio volumio[1163]: info: [ytmusic] Obtained PO token for video #rKUieRwoYAI: MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt Jan 25 18:32:09 volumio volumio[1163]: info: [ytmusic] (Nước Ngoài) validating stream URL "https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00"... Jan 25 18:32:09 volumio volumio[1163]: info: [ytmusic] (Nước Ngoài) stream validated in 0.025s. Jan 25 18:32:09 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand addid "https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00&t.YouTube" Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: sendMpdCommand addid "https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00&t.YouTube" took 1 milliseconds Jan 25 18:32:09 volumio volumio[1163]: verbose: MPD COMMAND [object Object] Jan 25 18:32:09 volumio volumio[1163]: verbose: MPD COMMAND [object Object] Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 2ms Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 1ms Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 1ms Jan 25 18:32:09 volumio volumio[1163]: info: [ytmusic-play] Prefetched and added track to MPD queue: Nước Ngoài Jan 25 18:32:09 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand consume 1 Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: Jan 25 18:32:09 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:09 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 2ms Jan 25 18:32:09 volumio volumio[1163]: info: sendMpdCommand consume 1 took 1 milliseconds Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 1ms Jan 25 18:32:09 volumio volumio[1163]: info: ------------------------------ 2ms Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 18:32:10 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:10 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:10 volumio volumio[1163]: info: CorePlayQueue::getTrack 5 Jan 25 18:32:10 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:12 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::startPlaybackTimer Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:13 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces state update: player Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::getState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand status Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:13 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces state update: player Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::getState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand status Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces system playlist update Jan 25 18:32:13 volumio volumio[1163]: info: Ignoring MPD Status Update Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::getState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand status Jan 25 18:32:13 volumio volumio[1163]: info: Jan 25 18:32:13 volumio volumio[1163]: ---------------------------- MPD announces state update: player Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::getState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand status Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 28ms Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand status took 28 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 28ms Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand status took 28 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand status took 27 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 28ms Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand status took 27 milliseconds Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseState Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 25 18:32:13 volumio volumio[1163]: info: sendMpdCommand playlistinfo took 0 milliseconds Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseTrackInfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseTrackInfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseTrackInfo Jan 25 18:32:13 volumio volumio[1163]: verbose: ControllerMpd::parseTrackInfo Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::servicePushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: verbose: STATE SERVICE {"status":"play","position":0,"seek":39,"duration":217,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Nước Ngoài","artist":"Bùi Anh Tuấn & Phan Mạnh Quỳnh ","album":null,"uri":"https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jan 25 18:32:13 volumio volumio[1163]: verbose: CURRENT POSITION 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState stateService play Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState currentStatus play Jan 25 18:32:13 volumio volumio[1163]: info: Received an update from plugin. extracting info from payload Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::servicePushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49,"duration":217,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Nước Ngoài","artist":"Bùi Anh Tuấn & Phan Mạnh Quỳnh ","album":null,"uri":"https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jan 25 18:32:13 volumio volumio[1163]: verbose: CURRENT POSITION 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState stateService play Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState currentStatus play Jan 25 18:32:13 volumio volumio[1163]: info: Received an update from plugin. extracting info from payload Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: ControllerMpd::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::servicePushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: verbose: STATE SERVICE {"status":"play","position":0,"seek":69,"duration":217,"samplerate":48,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Nước Ngoài","artist":"Bùi Anh Tuấn & Phan Mạnh Quỳnh ","album":null,"uri":"https://rr7---sn-8pxuuxa-i5oes.googlevideo.com/videoplayback?expire=1769362328&ei=OP91acXlM-2MqL8P87OvmAk&ip=117.1.142.71&id=o-ADQ681_aR3nseBL_EWDC9BpxiKboWZPB6Cta-8_f0W8n&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&cps=215&met=1769340728%2C&mh=om&mm=31%2C29&mn=sn-8pxuuxa-i5oes%2Csn-8pxuuxa-i5ozz&ms=au%2Crdu&mv=m&mvi=7&pl=21&rms=au%2Cau&initcwndbps=2953750&bui=AW-iu_rhbQYzrexSYUBJZ2iW1ViWoUlChsJSoX5TvXCnkL6MrpA5jV67YxO56UBDLD-1mXzT1JFFztqq&spc=q5xjPHN_RXAGak3Sy4nsibNI0NgBGqDOKxzgECGl7RIpwc9YY9e-JeIGxRpehitzONQ&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=UszgdB56_aXCxLy-CNQXWR4S&rqh=1&gir=yes&clen=3755061&dur=216.781&lmt=1744162492202718&mt=1769340301&fvip=1&keepalive=yes&fexp=51552689%2C51565116%2C51565681%2C51580968&c=WEB_REMIX&sefc=1&txp=4532534&n=iXKVvQ8kKSLT9g&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=APaTxxMwRAIgdqRUUXevKDvuII_7tmj3zGh5ojtg57YN8_Tn8kzC8LICIE0I6YwnYG5hl0y0IlQNOQkGy2IYSI4mDkdmMyNmmpdh&sig=AJEij0EwRQIgQCclwstSAaC13gyD_JmS91bKcjyV2-CD-OutdSFzPDoCIQD9-6HJwrQJJFWzMf-Jme6vpotbgK_l9w-Zw8-eFkj8gw%3D%3D&pot=MlUv2GOz0Iqx4i_mFYkkR7-ZBlK48LQU-6zD6SmB1qc8Fm6LMx90wKVm_R-E89zsEtIbzkzZO8jTMC8mLmej1L-gL02FqZrTEk-wRIjfMOCzNguQ5oIt&cver=1.20250219.01.00&t.YouTube","trackType":"YouTube"} Jan 25 18:32:13 volumio volumio[1163]: verbose: CURRENT POSITION 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState stateService play Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::syncState currentStatus play Jan 25 18:32:13 volumio volumio[1163]: info: Received an update from plugin. extracting info from payload Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: CoreStateMachine::pushState Jan 25 18:32:13 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:13 volumio volumio[1163]: info: CoreCommandRouter::volumioPushState Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 51ms Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 51ms Jan 25 18:32:13 volumio volumio[1163]: info: ------------------------------ 50ms Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 25 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:13 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:17 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:17 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:17 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17:3000 from 192.168.1.15 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 25 18:32:17 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 18:32:21 volumio volumio[1163]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 25 18:32:21 volumio volumio[1163]: info: Received Get System Version Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 18:32:21 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:21 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:21 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:21 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:22 volumio volumio[1163]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 18:32:28 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:28 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:28 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:28 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:28 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:28 volumio sudo[9613]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:28 volumio sudo[9613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:28 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:28 volumio systemd[1]: go-librespot-daemon.service: Killing process 1936 (go-librespot) with signal SIGKILL. Jan 25 18:32:28 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:28 volumio volumio[1163]: info: Connection to go-librespot Websocket closed Jan 25 18:32:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:28 volumio go-librespot[9615]: go-librespot daemon starting... Jan 25 18:32:28 volumio sudo[9613]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=debug msg="app state loaded" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=info msg="zeroconf server listening on port 33881" Jan 25 18:32:28 volumio go-librespot[9616]: time="2026-01-25T18:32:28+07:00" level=debug msg="obtained new client token: AACXgsbqvgQzG86yHclLGAjtcxGcoWc1DasfxZsofOXeJAPtq06EM8lHxxh3a2FNGz6kbiWPDPKMHnFldr3eTisPsxrcUFikaS8K6VxA/o9wUtFBeaaEtbBUkB8vLgJOm6SmSBEp328Am6NLo/eShNuPboXf0AC+WRQylnfwqNlj8bOfkvecQn3VzEwwKNNvMCZc12JeDaec4UVTrg5yXWCVzo55ZrJUQHxiw97pHgvCput19s7iCSI=" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="completed keyexchange" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="completed challenge" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=info msg="authenticated AP" username="31************************na" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=info msg="authenticated Login5" username="31************************na" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="initializing zeroconf session" username="31************************na" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="dealer connection opened" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=trace msg="starting accesspoint recv loop" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=trace msg="starting dealer recv loop" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=trace msg="received accesspoint ping" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="received connection id: OWU0ZDI3YzItMDIy...OTQ0NENFN0I2RQ==" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=trace msg="received accesspoint pong ack" Jan 25 18:32:29 volumio go-librespot[9616]: time="2026-01-25T18:32:29+07:00" level=debug msg="put connect state because NEW_DEVICE" Jan 25 18:32:31 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket Jan 25 18:32:31 volumio go-librespot[9616]: time="2026-01-25T18:32:31+07:00" level=debug msg="new websocket client" Jan 25 18:32:31 volumio volumio[1163]: info: Connection to go-librespot Websocket established Jan 25 18:32:31 volumio volumio[1163]: info: go-librespot daemon successfully initialized Jan 25 18:32:34 volumio volumio[1163]: info: Getting Spotify volume Jan 25 18:32:34 volumio volumio[1163]: info: Spotify volume: 100 Jan 25 18:32:34 volumio volumio[1163]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jan 25 18:32:34 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket Jan 25 18:32:34 volumio go-librespot[9616]: time="2026-01-25T18:32:34+07:00" level=debug msg="new websocket client" Jan 25 18:32:34 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:34 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:34 volumio volumio[1163]: info: Connection to go-librespot Websocket established Jan 25 18:32:34 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:34 volumio volumio[1163]: SPOTIFY: SPOTIFY VOLUME 100 Jan 25 18:32:34 volumio volumio[1163]: SPOTIFY: VOLUMIO VOLUME 24 Jan 25 18:32:34 volumio volumio[1163]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 25 18:32:34 volumio volumio[1163]: info: Setting Spotify Volume from Volumio: 24 Jan 25 18:32:36 volumio volumio[1163]: SPOTIFY: SETTING SPOTIFY VOLUME 24 Jan 25 18:32:36 volumio volumio[1163]: info: Sending Spotify command with payload to local API: /player/volume Jan 25 18:32:36 volumio go-librespot[9616]: time="2026-01-25T18:32:36+07:00" level=debug msg="update volume requested to 15728/65535" Jan 25 18:32:36 volumio go-librespot[9616]: time="2026-01-25T18:32:36+07:00" level=debug msg="put connect state because VOLUME_CHANGED" Jan 25 18:32:36 volumio go-librespot[9616]: time="2026-01-25T18:32:36+07:00" level=trace msg="emitting websocket event: volume" Jan 25 18:32:36 volumio volumio[1163]: SPOTIFY: received: {"type":"volume","data":{"value":24,"max":100}} Jan 25 18:32:36 volumio volumio[1163]: SPOTIFY: RECEIVED SPOTIFY VOLUME 24 Jan 25 18:32:36 volumio volumio[1163]: SPOTIFY: received: {"type":"volume","data":{"value":24,"max":100}} Jan 25 18:32:36 volumio volumio[1163]: SPOTIFY: RECEIVED SPOTIFY VOLUME 24 Jan 25 18:32:37 volumio volumio[1163]: info: Getting Spotify volume Jan 25 18:32:37 volumio volumio[1163]: info: Spotify volume: 24 Jan 25 18:32:37 volumio volumio[1163]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 25 18:32:37 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:37 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:37 volumio volumio[1163]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 25 18:32:40 volumio volumio[1163]: info: Received OAUTH Data Jan 25 18:32:40 volumio volumio[1163]: info: Executing Spotify Oauth Login Jan 25 18:32:40 volumio volumio[1163]: info: Saving Spotify Refresh Token Jan 25 18:32:41 volumio sudo[9696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 18:32:41 volumio sudo[9696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:41 volumio sudo[9696]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:41 volumio sudo[9698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 18:32:41 volumio sudo[9698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:41 volumio sudo[9698]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:41 volumio volumio[1163]: verbose: New Socket.io Connection to 192.168.1.17 from 192.168.1.15 UA: Mozilla/5.0 (Linux; Android 12; M2007J3SG Build/SKQ1.211006.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.193 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::volumioGetVisibleSources Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:41 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 25 18:32:41 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:41 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:41 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:41 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:41 volumio volumio[1163]: info: Listing playlists Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 25 18:32:41 volumio volumio[1163]: info: New Spotify access tokenBQA4rJ-OPe... Jan 25 18:32:41 volumio volumio[1163]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 25 18:32:41 volumio volumio[1163]: SPOTIFY: User informations: {"country":"VN","display_name":"Son Nguyen","email":"son62n@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31kpeeocxgi73kpx33ycwi5df7na"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31kpeeocxgi73kpx33ycwi5df7na","id":"31kpeeocxgi73kpx33ycwi5df7na","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1477531412386289&height=300&width=300&ext=1771932754&hash=AT8c-fagM7loyggPOiEbIz3V","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1477531412386289&height=50&width=50&ext=1771932754&hash=AT-IaqtQCGMS_lzdxgqbEypS","width":64}],"product":"free","type":"user","uri":"spotify:user:31kpeeocxgi73kpx33ycwi5df7na"} Jan 25 18:32:41 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:41 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:41 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:41 volumio sudo[9710]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:41 volumio sudo[9710]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:41 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:41 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:41 volumio volumio[1163]: info: Connection to go-librespot Websocket closed Jan 25 18:32:41 volumio volumio[1163]: info: Connection to go-librespot Websocket closed Jan 25 18:32:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:41 volumio go-librespot[9712]: go-librespot daemon starting... Jan 25 18:32:41 volumio sudo[9710]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=debug msg="app state loaded" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:41 volumio go-librespot[9713]: time="2026-01-25T18:32:41+07:00" level=info msg="zeroconf server listening on port 36273" Jan 25 18:32:42 volumio volumio[1163]: info: New Spotify access tokenBQAVw8xKtH... Jan 25 18:32:42 volumio volumio[1163]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="obtained new client token: AACmS+wrT3k0iwJv+Cf6a4Lg2dZu3Z2hiYNumqsEIaH4WIS9nmG8kIRm+BaHjYgKLsVpjWkTzzDIlX6Ew38GPOt5s9KZvlg373fLdEJ+N/hzDYFFFlMdYCugL+RQaQQmWndOoicj8sxRKx2UJmPqZYUL52D2mneSPDDIu9v/fDA7GuZV5hdvDrp0dL2L+PLuLJwq3+hKou+iOPclzVSUiue0MYbdUMpEarQwebos1CBkHBT0a6/LFgc=" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="completed keyexchange" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="completed challenge" Jan 25 18:32:42 volumio volumio[1163]: SPOTIFY: User informations: {"country":"VN","display_name":"Son Nguyen","email":"son62n@hotmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31kpeeocxgi73kpx33ycwi5df7na"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31kpeeocxgi73kpx33ycwi5df7na","id":"31kpeeocxgi73kpx33ycwi5df7na","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1477531412386289&height=300&width=300&ext=1771932754&hash=AT8c-fagM7loyggPOiEbIz3V","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=1477531412386289&height=50&width=50&ext=1771932754&hash=AT-IaqtQCGMS_lzdxgqbEypS","width":64}],"product":"free","type":"user","uri":"spotify:user:31kpeeocxgi73kpx33ycwi5df7na"} Jan 25 18:32:42 volumio volumio[1163]: info: Spotify Successfully logged in Jan 25 18:32:42 volumio volumio[1163]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 18:32:42 volumio volumio[1163]: info: [1769340762166] CoreMusicLibrary::Adding element Spotify Jan 25 18:32:42 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 18:32:42 volumio volumio[1163]: Cannot find translation for source SoundCloud Jan 25 18:32:42 volumio volumio[1163]: Cannot find translation for source YouTube2 Jan 25 18:32:42 volumio volumio[1163]: Cannot find translation for source YouTube Music Jan 25 18:32:42 volumio volumio[1163]: Cannot find translation for source Spotify Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=info msg="authenticated AP" username="31************************na" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=info msg="authenticated Login5" username="31************************na" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="initializing zeroconf session" username="31************************na" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="dealer connection opened" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=trace msg="starting accesspoint recv loop" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=trace msg="starting dealer recv loop" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=trace msg="received accesspoint ping" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="received connection id: MDliMmE0ZDYtMTBl...RUFEMUQyMDcyOA==" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=trace msg="received accesspoint pong ack" Jan 25 18:32:42 volumio go-librespot[9713]: time="2026-01-25T18:32:42+07:00" level=debug msg="put connect state because NEW_DEVICE" Jan 25 18:32:42 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 25 18:32:43 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 18:32:43 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:43 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:43 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:43 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:43 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:43 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:43 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 25 18:32:44 volumio volumio[1163]: info: Received Get System Info Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 25 18:32:44 volumio volumio[1163]: info: Discovery: Getting this device information Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::volumioGetState Jan 25 18:32:44 volumio volumio[1163]: info: CorePlayQueue::getTrack 6 Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 25 18:32:44 volumio volumio[1163]: info: Initializing connection to go-librespot Websocket Jan 25 18:32:44 volumio go-librespot[9713]: time="2026-01-25T18:32:44+07:00" level=debug msg="new websocket client" Jan 25 18:32:44 volumio volumio[1163]: info: Connection to go-librespot Websocket established Jan 25 18:32:44 volumio volumio[1163]: info: go-librespot daemon successfully initialized Jan 25 18:32:44 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:44 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:44 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:44 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:44 volumio sudo[9732]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:44 volumio sudo[9732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Killing process 9718 (go-librespot) with signal SIGKILL. Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio volumio[1163]: info: Connection to go-librespot Websocket closed Jan 25 18:32:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio sudo[9732]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:45 volumio go-librespot[9734]: go-librespot daemon starting... Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="app state loaded" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=info msg="zeroconf server listening on port 33471" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="obtained new client token: AACoilskElhC/sw+vwGRdZvlNe6N1JS9rG25StkvewfQ9CW0wn3yerxo3MZmiBFxtfbdvVEJd7B7xilnU2E7bolPPw+WM2m345GPMlaw5O6zZ2OghV7kaki09Qj9LwMTTBf8LB8fWqSe7EXp9lnVXF5Vrg086iTu2ZBljXaPzopJcNO3Pi+VChpXxMU5PvYI6WpFli/NlPaUQnRHwvnhV+B+/sXiPWL2/wTyylGl3xZgOYTtV1QoQhg=" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+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" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="completed keyexchange" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="completed challenge" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=info msg="authenticated AP" username="31************************na" Jan 25 18:32:45 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:45 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:45 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:45 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:45 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:45 volumio sudo[9749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:45 volumio sudo[9749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=info msg="authenticated Login5" username="31************************na" Jan 25 18:32:45 volumio go-librespot[9735]: time="2026-01-25T18:32:45+07:00" level=debug msg="initializing zeroconf session" username="31************************na" Jan 25 18:32:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Killing process 9745 (go-librespot) with signal SIGKILL. Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio sudo[9749]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:45 volumio go-librespot[9751]: go-librespot daemon starting... Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=debug msg="app state loaded" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:45 volumio go-librespot[9752]: time="2026-01-25T18:32:45+07:00" level=info msg="zeroconf server listening on port 37309" Jan 25 18:32:45 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:45 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:45 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:45 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:45 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:45 volumio sudo[9762]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:45 volumio sudo[9762]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:45 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Killing process 9756 (go-librespot) with signal SIGKILL. Jan 25 18:32:45 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:45 volumio go-librespot[9764]: go-librespot daemon starting... Jan 25 18:32:45 volumio sudo[9762]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:45 volumio go-librespot[9766]: time="2026-01-25T18:32:45+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:45 volumio go-librespot[9766]: time="2026-01-25T18:32:45+07:00" level=debug msg="app state loaded" Jan 25 18:32:45 volumio go-librespot[9766]: time="2026-01-25T18:32:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:46 volumio go-librespot[9766]: time="2026-01-25T18:32:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:46 volumio go-librespot[9766]: time="2026-01-25T18:32:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:46 volumio go-librespot[9766]: time="2026-01-25T18:32:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:46 volumio go-librespot[9766]: time="2026-01-25T18:32:46+07:00" level=info msg="zeroconf server listening on port 38461" Jan 25 18:32:46 volumio go-librespot[9766]: time="2026-01-25T18:32:46+07:00" level=debug msg="obtained new client token: AAAYFcp/czo63oHJRjtVcrxruRnww0FPvN55INn9qSuXV6FlSnIsA/eKFeWqfyPFNZsWMp3TNaWj+4k0ae8M5uBodhTx6WXFNExMrB2OBBlcphEr5Pa5tngn/VSRKcN79TrpvB9yBDfy4ilLT8ZYj4qei5VrE4SfsZqBzZ4Jrqzi0rFfKdsvYZLHkTuil/ryWKRTIx4Un9xzdRXN1b7UzUfQoMNE9l7XzYFVWce2etJ1dEcc5zad" Jan 25 18:32:46 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:46 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:46 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:46 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:46 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:46 volumio sudo[9778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:46 volumio sudo[9778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:46 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:46 volumio systemd[1]: go-librespot-daemon.service: Killing process 9771 (go-librespot) with signal SIGKILL. Jan 25 18:32:46 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:46 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:46 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:46 volumio go-librespot[9780]: go-librespot daemon starting... Jan 25 18:32:46 volumio sudo[9778]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=info msg="running go-librespot 0.6.2" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="app state loaded" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=info msg="zeroconf server listening on port 38629" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="obtained new client token: AABp+XDir0p//q9HKkmSo57oTp3OcBx7m4MQaCoDv5IKui/FMWdLsGM4PUxaZDwTTWtc8476bAOVtEpSwIg63Bsev44amz7tvBXSBstJMgC1s1g292PmJWbZ3Xwz5Zgs8zkjETrfP2Qu18As8XQx7HrJGJfaOzUJN4uIqYMti4ZPjic/xGIAC07ABpvFizU7TXN4yeD5g23vFAsD6VHbh9h4TeBMRXlk0H1Sr60htag/qZ08eqXqdpo=" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="completed keyexchange" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="completed challenge" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=info msg="authenticated AP" username="31************************na" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=info msg="authenticated Login5" username="31************************na" Jan 25 18:32:46 volumio go-librespot[9781]: time="2026-01-25T18:32:46+07:00" level=debug msg="initializing zeroconf session" username="31************************na" Jan 25 18:32:47 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:47 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:47 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:47 volumio sudo[9793]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio sudo[9793]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:47 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Killing process 9790 (go-librespot) with signal SIGKILL. Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 18:32:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 25 18:32:47 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:47 volumio sudo[9793]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:47 volumio volumio[1163]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:47 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:47 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:47 volumio sudo[9798]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio sudo[9798]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 25 18:32:47 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:47 volumio sudo[9798]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:47 volumio volumio[1163]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Jan 25 18:32:47 volumio volumio[1163]: info: Creating Spotify config file Jan 25 18:32:47 volumio volumio[1163]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 18:32:47 volumio volumio[1163]: info: Spotify config file written Jan 25 18:32:47 volumio sudo[9802]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio sudo[9802]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Start request repeated too quickly. Jan 25 18:32:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'start-limit-hit'. Jan 25 18:32:47 volumio systemd[1]: Failed to start go-librespot-daemon.service - go-librespot Daemon. Jan 25 18:32:47 volumio sudo[9802]: pam_unix(sudo:session): session closed for user root Jan 25 18:32:47 volumio volumio[1163]: error: Cannot start Go-librespot Daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: error: Error initializing go-librespot daemon: Error: Command failed: /usr/bin/sudo systemctl restart go-librespot-daemon.service Jan 25 18:32:47 volumio volumio[1163]: Job for go-librespot-daemon.service failed because start of the service was attempted too often. Jan 25 18:32:47 volumio volumio[1163]: See "systemctl status go-librespot-daemon.service" and "journalctl -xeu go-librespot-daemon.service" for details. Jan 25 18:32:47 volumio volumio[1163]: To force a start use "systemctl reset-failed go-librespot-daemon.service" Jan 25 18:32:47 volumio volumio[1163]: followed by "systemctl start go-librespot-daemon.service" again. Jan 25 18:32:47 volumio volumio[1163]: info: Getting Spotify volume Jan 25 18:32:47 volumio volumio[1163]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 18:32:47 volumio volumio[1163]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 18:32:47 volumio volumio[1163]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 18:32:47 volumio volumio[1163]: errno: -111, Jan 25 18:32:47 volumio volumio[1163]: code: 'ECONNREFUSED', Jan 25 18:32:47 volumio volumio[1163]: syscall: 'connect', Jan 25 18:32:47 volumio volumio[1163]: address: '127.0.0.1', Jan 25 18:32:47 volumio volumio[1163]: port: 9879, Jan 25 18:32:47 volumio volumio[1163]: response: undefined Jan 25 18:32:47 volumio volumio[1163]: } Jan 25 18:32:47 volumio volumio[1163]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 18:32:47 volumio sudo[9819]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 18:31' Jan 25 18:32:47 volumio sudo[9819]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 21:07:15 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4b5c74f40f473b90a542bf010b97924b"