May 26 13:38:44 megosmusic systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... May 26 13:38:44 megosmusic systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. May 26 13:38:44 megosmusic systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. May 26 13:38:44 megosmusic systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. May 26 13:39:09 megosmusic nmbd[1109]: [2026/05/26 13:39:09.812598, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 26 13:39:09 megosmusic nmbd[1109]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.50.33 for name WORKGROUP<1d>. May 26 13:39:09 megosmusic nmbd[1109]: This response was from IP 192.168.50.155, reporting an IP address of 192.168.50.156. May 26 13:39:09 megosmusic nmbd[1109]: [2026/05/26 13:39:09.813960, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 26 13:39:09 megosmusic nmbd[1109]: query_name_response: Multiple (3) responses received for a query on subnet 192.168.50.33 for name WORKGROUP<1d>. May 26 13:39:09 megosmusic nmbd[1109]: This response was from IP 192.168.50.155, reporting an IP address of 192.168.50.156. May 26 13:39:09 megosmusic nmbd[1109]: [2026/05/26 13:39:09.814605, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 26 13:39:09 megosmusic nmbd[1109]: query_name_response: Multiple (4) responses received for a query on subnet 192.168.50.33 for name WORKGROUP<1d>. May 26 13:39:09 megosmusic nmbd[1109]: This response was from IP 192.168.50.155, reporting an IP address of 192.168.50.156. May 26 13:39:09 megosmusic nmbd[1109]: [2026/05/26 13:39:09.815069, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 26 13:39:09 megosmusic nmbd[1109]: query_name_response: Multiple (5) responses received for a query on subnet 192.168.50.33 for name WORKGROUP<1d>. May 26 13:39:09 megosmusic nmbd[1109]: This response was from IP 192.168.50.156, reporting an IP address of 192.168.50.156. May 26 13:39:09 megosmusic nmbd[1109]: [2026/05/26 13:39:09.815227, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 26 13:39:09 megosmusic nmbd[1109]: query_name_response: Multiple (6) responses received for a query on subnet 192.168.50.33 for name WORKGROUP<1d>. May 26 13:39:09 megosmusic nmbd[1109]: This response was from IP 192.168.50.156, reporting an IP address of 192.168.50.156. May 26 13:39:12 megosmusic volumio[1241]: verbose: New Socket.io Connection to 192.168.50.33 from 192.168.50.47 UA: Mozilla/5.0 (Linux; Android 16; SM-S9280 Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/148.0.7778.178 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 May 26 13:39:12 megosmusic volumio[1241]: info: Received Get System Info May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 13:39:12 megosmusic volumio[1241]: info: Discovery: Getting this device information May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:12 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:12 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetVisibleSources May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:12 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 26 13:39:12 megosmusic volumio[1241]: info: Received Get System Info May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 13:39:12 megosmusic volumio[1241]: info: Discovery: Getting this device information May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:12 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:12 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:12 megosmusic volumio[1241]: info: Listing playlists May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:12 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:13 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:13 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:13 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:13 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 26 13:39:34 megosmusic volumio[1241]: info: Received OAUTH Data May 26 13:39:34 megosmusic volumio[1241]: info: Executing Spotify Oauth Login May 26 13:39:34 megosmusic volumio[1241]: info: Saving Spotify Refresh Token May 26 13:39:35 megosmusic sudo[5041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 26 13:39:35 megosmusic sudo[5041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:35 megosmusic sudo[5041]: pam_unix(sudo:session): session closed for user root May 26 13:39:35 megosmusic sudo[5043]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 26 13:39:35 megosmusic sudo[5043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:35 megosmusic sudo[5043]: pam_unix(sudo:session): session closed for user root May 26 13:39:35 megosmusic volumio[1241]: verbose: New Socket.io Connection to 192.168.50.33 from 192.168.50.95 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetVisibleSources May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:35 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 26 13:39:35 megosmusic volumio[1241]: info: Received Get System Info May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 13:39:35 megosmusic volumio[1241]: info: Discovery: Getting this device information May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:35 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:35 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:35 megosmusic volumio[1241]: info: Listing playlists May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::getUIConfigOnPlugin May 26 13:39:35 megosmusic volumio[1241]: info: New Spotify access tokenBQBJyqG0VU... May 26 13:39:35 megosmusic volumio[1241]: info: Spotify credentials grant success - running version from March 24, 2019 May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 26 13:39:35 megosmusic volumio[1241]: SPOTIFY: User informations: {"country":"TW","display_name":"sound300w","email":"sound300w@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/sound300w"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/sound300w","id":"sound300w","images":[],"product":"free","type":"user","uri":"spotify:user:sound300w"} May 26 13:39:35 megosmusic volumio[1241]: info: Creating Spotify config file May 26 13:39:35 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 13:39:35 megosmusic volumio[1241]: info: Spotify config file written May 26 13:39:35 megosmusic sudo[5048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 13:39:35 megosmusic sudo[5048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:35 megosmusic systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 13:39:35 megosmusic systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 13:39:35 megosmusic systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:35 megosmusic volumio[1241]: info: Connection to go-librespot Websocket closed May 26 13:39:35 megosmusic systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:35 megosmusic go-librespot[5050]: go-librespot daemon starting... May 26 13:39:35 megosmusic sudo[5048]: pam_unix(sudo:session): session closed for user root May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="running go-librespot 0.7.1" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="app state loaded" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="stored credentials not found" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08: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-gew1.spotify.com:80]" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="zeroconf server listening on port 43619" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="obtained new client token: AACTlfhD3cMxawRRbmEY/eqoOLp+eQ2r7oMrQzgphWrTgKEmttX1BiMsOsOQyAfDO/QwqVmcWDNRmKQt0gUywGf4myXsopL6X97ZRzLyYarQ3HqRYEL2AZgzcPhxKQZ4OxZMdJ/KKnUSvrWtWlKqlCVmVzu1l/wvy7mmvvXhnu6hNfKCtqSdZV2B04UOYqK0I7Dp6NpmWGT42L00eeHpXssFC7mK5m6aV+8mgkuvecJMTJiagkij39E=" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08: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" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="connected to ap-gae2.spotify.com:443" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="completed keyexchange" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="completed challenge" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="authenticated AP" username="so*****0w" May 26 13:39:36 megosmusic volumio[1241]: info: New Spotify access tokenBQDBwuTf5Z... May 26 13:39:36 megosmusic volumio[1241]: info: Spotify credentials grant success - running version from March 24, 2019 May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=info msg="authenticated Login5" username="so*****0w" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="stored credentials" username="so*****0w" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="initializing zeroconf session" username="so*****0w" May 26 13:39:36 megosmusic volumio[1241]: SPOTIFY: User informations: {"country":"TW","display_name":"sound300w","email":"sound300w@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/sound300w"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/sound300w","id":"sound300w","images":[],"product":"free","type":"user","uri":"spotify:user:sound300w"} May 26 13:39:36 megosmusic volumio[1241]: info: Spotify Successfully logged in May 26 13:39:36 megosmusic volumio[1241]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 26 13:39:36 megosmusic volumio[1241]: info: [1779773976525] CoreMusicLibrary::Adding element Spotify May 26 13:39:36 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 26 13:39:36 megosmusic volumio[1241]: Cannot find translation for source YouTube Music May 26 13:39:36 megosmusic volumio[1241]: Cannot find translation for source 80s80s Radio May 26 13:39:36 megosmusic volumio[1241]: Cannot find translation for source Volusonic May 26 13:39:36 megosmusic volumio[1241]: Cannot find translation for source Podcast May 26 13:39:36 megosmusic volumio[1241]: Cannot find translation for source Spotify May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="dealer connection opened" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=trace msg="starting accesspoint recv loop" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=trace msg="starting dealer recv loop" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=trace msg="received accesspoint ping" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="received connection id: YzQ2OTAxNDktOGQx...RUFFNkE5QjQ5Mw==" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=trace msg="received accesspoint pong ack" May 26 13:39:36 megosmusic go-librespot[5051]: time="2026-05-26T13:39:36+08:00" level=debug msg="put connect state because NEW_DEVICE" May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 26 13:39:37 megosmusic volumio[1241]: info: Received Get System Info May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 13:39:37 megosmusic volumio[1241]: info: Discovery: Getting this device information May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:37 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:37 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 13:39:38 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 26 13:39:38 megosmusic volumio[1241]: info: Received Get System Info May 26 13:39:38 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 26 13:39:38 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 26 13:39:38 megosmusic volumio[1241]: info: Discovery: Getting this device information May 26 13:39:38 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:38 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:38 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 26 13:39:38 megosmusic volumio[1241]: info: Initializing connection to go-librespot Websocket May 26 13:39:38 megosmusic go-librespot[5051]: time="2026-05-26T13:39:38+08:00" level=debug msg="new websocket client" May 26 13:39:38 megosmusic volumio[1241]: info: Connection to go-librespot Websocket established May 26 13:39:38 megosmusic volumio[1241]: info: go-librespot daemon successfully initialized May 26 13:39:39 megosmusic volumio[1241]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 13:39:39 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 13:39:39 megosmusic volumio[1241]: info: Creating Spotify config file May 26 13:39:39 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 13:39:39 megosmusic volumio[1241]: info: Spotify config file written May 26 13:39:39 megosmusic sudo[5075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 13:39:39 megosmusic sudo[5075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:39 megosmusic systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 13:39:39 megosmusic systemd[1]: go-librespot-daemon.service: Killing process 5053 (go-librespot) with signal SIGKILL. May 26 13:39:39 megosmusic volumio[1241]: info: Connection to go-librespot Websocket closed May 26 13:39:39 megosmusic systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 13:39:39 megosmusic systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:39 megosmusic systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:39 megosmusic go-librespot[5077]: go-librespot daemon starting... May 26 13:39:39 megosmusic sudo[5075]: pam_unix(sudo:session): session closed for user root May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=info msg="running go-librespot 0.7.1" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=debug msg="app state loaded" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08: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]" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08: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]" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08: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]" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=info msg="zeroconf server listening on port 40099" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 13:39:39 megosmusic go-librespot[5078]: time="2026-05-26T13:39:39+08:00" level=debug msg="obtained new client token: AAAtWIyZjQl8wBd3dj2w0oocAC+gu+OY5YDJwkm6I6ESULXA3Jjd2OMLOe6ZsKApKY/GeM51TZuLnPEcfAgmO38Mj7X29xT6r0wSb3wwUEw8YLzu8Zb1fXjni044nrj3SPDhyf570vvbu0D16nbvoa9+tXIeC7iHzeCdwVjvWXmI8bi3Z8WLFC6O3dU5DjFLvqwj7dlwZHIxHtQge4BnA+rZhGl0/3LEmkYEy1USNuUxzAHFnVtLKvx/gw==" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="completed keyexchange" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="completed challenge" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=info msg="authenticated AP" username="so*****0w" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=info msg="authenticated Login5" username="so*****0w" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="initializing zeroconf session" username="so*****0w" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="dealer connection opened" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=trace msg="starting accesspoint recv loop" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=trace msg="starting dealer recv loop" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=trace msg="received accesspoint ping" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="received connection id: ZTc0MDE1M2MtMjIy...OURENzQyMUQ1OQ==" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=trace msg="received accesspoint pong ack" May 26 13:39:40 megosmusic go-librespot[5078]: time="2026-05-26T13:39:40+08:00" level=debug msg="put connect state because NEW_DEVICE" May 26 13:39:41 megosmusic volumio[1241]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 13:39:41 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 13:39:41 megosmusic volumio[1241]: info: Creating Spotify config file May 26 13:39:41 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 13:39:41 megosmusic volumio[1241]: info: Spotify config file written May 26 13:39:41 megosmusic sudo[5088]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 13:39:41 megosmusic sudo[5088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:41 megosmusic systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 13:39:41 megosmusic systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 13:39:41 megosmusic systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:41 megosmusic systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:41 megosmusic go-librespot[5090]: go-librespot daemon starting... May 26 13:39:41 megosmusic sudo[5088]: pam_unix(sudo:session): session closed for user root May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=info msg="running go-librespot 0.7.1" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=debug msg="app state loaded" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 13:39:41 megosmusic volumio[1241]: info: Getting Spotify volume May 26 13:39:41 megosmusic volumio[1241]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08: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]" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08: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]" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08: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]" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=info msg="zeroconf server listening on port 42037" May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 13:39:41 megosmusic volumio[1241]: info: CoreCommandRouter::volumioGetState May 26 13:39:41 megosmusic volumio[1241]: info: CorePlayQueue::getTrack 0 May 26 13:39:41 megosmusic volumio[1241]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 26 13:39:41 megosmusic volumio[1241]: info: Initializing connection to go-librespot Websocket May 26 13:39:41 megosmusic go-librespot[5091]: time="2026-05-26T13:39:41+08:00" level=debug msg="new websocket client" May 26 13:39:41 megosmusic volumio[1241]: info: Connection to go-librespot Websocket established May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=debug msg="obtained new client token: AAAuWghHFO7H8zdBshznA1M8ONq/yBgbxg+kUX27c8/Hn0N8e+HMBac98d+FO6+FjGaPZm9+eC5cHKBc3AqNyhj9INzODHZCjScaohtNl9LHBnk53Ksm6MDeg9Pr4dSz8SrEGqFp0zckCa1/LBvyw0B8fR+a0yKQMMrr++D9+85rS1ignjcjW4TZQjkzN8UfyBo8KnlD//AqWS7XHynKToyWSH3bYc35nVz8N7ZAKmZUSbHU0M8GQvY=" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08: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" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08: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" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=debug msg="connected to ap-gae2.spotify.com:80" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=debug msg="completed keyexchange" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=debug msg="completed challenge" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=info msg="authenticated AP" username="so*****0w" May 26 13:39:42 megosmusic volumio[1241]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] May 26 13:39:42 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings May 26 13:39:42 megosmusic volumio[1241]: info: Creating Spotify config file May 26 13:39:42 megosmusic volumio[1241]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 26 13:39:42 megosmusic volumio[1241]: info: Spotify config file written May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=info msg="authenticated Login5" username="so*****0w" May 26 13:39:42 megosmusic go-librespot[5091]: time="2026-05-26T13:39:42+08:00" level=debug msg="initializing zeroconf session" username="so*****0w" May 26 13:39:42 megosmusic sudo[5101]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 26 13:39:42 megosmusic sudo[5101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:42 megosmusic systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... May 26 13:39:42 megosmusic systemd[1]: go-librespot-daemon.service: Killing process 5099 (go-librespot) with signal SIGKILL. May 26 13:39:42 megosmusic systemd[1]: go-librespot-daemon.service: Deactivated successfully. May 26 13:39:42 megosmusic systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:42 megosmusic volumio[1241]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 13:39:42 megosmusic volumio[1241]: Error: socket hang up May 26 13:39:42 megosmusic volumio[1241]: at connResetException (node:internal/errors:720:14) May 26 13:39:42 megosmusic volumio[1241]: at Socket.socketOnEnd (node:_http_client:519:23) May 26 13:39:42 megosmusic volumio[1241]: at Socket.emit (node:events:526:35) May 26 13:39:42 megosmusic volumio[1241]: at endReadableNT (node:internal/streams/readable:1376:12) May 26 13:39:42 megosmusic volumio[1241]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { May 26 13:39:42 megosmusic volumio[1241]: code: 'ECONNRESET', May 26 13:39:42 megosmusic volumio[1241]: response: undefined May 26 13:39:42 megosmusic volumio[1241]: } May 26 13:39:42 megosmusic volumio[1241]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 13:39:42 megosmusic systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. May 26 13:39:42 megosmusic go-librespot[5103]: go-librespot daemon starting... May 26 13:39:42 megosmusic sudo[5101]: pam_unix(sudo:session): session closed for user root May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="running go-librespot 0.7.1" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="app state loaded" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="api server listening on 127.0.0.1:9879" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08: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]" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08: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]" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08: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]" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="zeroconf server listening on port 42059" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="using avahi-daemon avahi 0.8 for mDNS service registration" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="obtained new client token: AAA0P2z3sckYnj4PfXse6Soxw4imgBNqBvdcFIbsL5FWptOBhvknKTFkmgGZzIQWYC8hWTE8JV0bVczfcZPVkXhRe4gxDgzINDytfPc2uFQFV1x5adnosv2dT0A5QNWJubR3ISuU5lmKe6pzqYkQAGQJXelvdQGKbEFnkUb83gQGZywDJ+7lNbx/dVFJr6xiCxTRu4y01jvYqvG3ypkxQ620vqT2Y0nVezLGPNENYCzuxEn/JMe8TJgCrg==" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="completed keyexchange" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="completed challenge" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="authenticated AP" username="so*****0w" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=info msg="authenticated Login5" username="so*****0w" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="initializing zeroconf session" username="so*****0w" May 26 13:39:42 megosmusic sudo[5127]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-26 13:38' May 26 13:39:42 megosmusic sudo[5127]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="dealer connection opened" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=trace msg="starting accesspoint recv loop" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=trace msg="starting dealer recv loop" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=trace msg="received accesspoint ping" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=debug msg="received connection id: YjI3MTRkYTItNjFh...M0ZBQUUzNENCQg==" May 26 13:39:42 megosmusic go-librespot[5115]: time="2026-05-26T13:39:42+08:00" level=trace msg="received accesspoint pong ack" PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"