-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2026-03-15 10:36:23 CET. -- Mar 15 10:35:01 smsl-n100 ntpd[3107]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Mar 15 10:35:07 smsl-n100 volumio-remote-updater[506]: [2026-03-15 10:35:07] [connect] Successful connection Mar 15 10:35:09 smsl-n100 go-librespot[3148]: time="2026-03-15T10:35:09+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Mar 15 10:35:09 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:09 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:10 smsl-n100 wpa_supplicant[852]: wlan0: CTRL-EVENT-DISCONNECTED bssid=b4:f2:67:19:99:a7 reason=0 Mar 15 10:35:10 smsl-n100 dhcpcd[564]: wlan0: carrier lost Mar 15 10:35:10 smsl-n100 wpa_supplicant[852]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Mar 15 10:35:10 smsl-n100 avahi-daemon[505]: Withdrawing address record for 192.168.0.165 on wlan0. Mar 15 10:35:10 smsl-n100 avahi-daemon[505]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.165. Mar 15 10:35:10 smsl-n100 avahi-daemon[505]: Interface wlan0.IPv4 no longer relevant for mDNS. Mar 15 10:35:10 smsl-n100 dhcpcd[564]: wlan0: deleting route to 192.168.0.0/24 Mar 15 10:35:10 smsl-n100 dhcpcd[564]: wlan0: deleting default route via 192.168.0.1 Mar 15 10:35:12 smsl-n100 ntpd[3107]: Deleting interface #3 wlan0, 192.168.0.165#123, interface stats: received=0, sent=0, dropped=0, active_time=48 secs Mar 15 10:35:12 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:12 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Mar 15 10:35:12 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:12 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:12 smsl-n100 go-librespot[3272]: go-librespot daemon starting... Mar 15 10:35:12 smsl-n100 go-librespot[3272]: time="2026-03-15T10:35:12+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:12 smsl-n100 go-librespot[3272]: time="2026-03-15T10:35:12+01:00" level=debug msg="app state loaded" Mar 15 10:35:12 smsl-n100 go-librespot[3272]: time="2026-03-15T10:35:12+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:12 smsl-n100 go-librespot[3272]: time="2026-03-15T10:35:12+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:12 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:12 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:14 smsl-n100 vtcs[2873]: [2026-03-15 10:35:14.075] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Mar 15 10:35:14 smsl-n100 systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:14 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:14 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:14 smsl-n100 systemd[1]: volumio.service: Failed with result 'exit-code'. Mar 15 10:35:14 smsl-n100 systemd[1]: Started dynamicswap service. Mar 15 10:35:14 smsl-n100 systemd[1]: dynamicswap.service: Succeeded. Mar 15 10:35:14 smsl-n100 systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Mar 15 10:35:14 smsl-n100 systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Mar 15 10:35:14 smsl-n100 systemd[1]: Stopped Volumio Backend Module. Mar 15 10:35:14 smsl-n100 systemd[1]: Started Volumio Backend Module. Mar 15 10:35:14 smsl-n100 systemd[1]: Started dynamicswap service. Mar 15 10:35:14 smsl-n100 systemd[1]: dynamicswap.service: Succeeded. Mar 15 10:35:15 smsl-n100 ntpd[3107]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Mar 15 10:35:15 smsl-n100 ntpd[3107]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Mar 15 10:35:15 smsl-n100 ntpd[3107]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Mar 15 10:35:15 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:15 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Mar 15 10:35:15 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:15 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:15 smsl-n100 go-librespot[3299]: go-librespot daemon starting... Mar 15 10:35:15 smsl-n100 go-librespot[3299]: time="2026-03-15T10:35:15+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:15 smsl-n100 go-librespot[3299]: time="2026-03-15T10:35:15+01:00" level=debug msg="app state loaded" Mar 15 10:35:15 smsl-n100 go-librespot[3299]: time="2026-03-15T10:35:15+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:16 smsl-n100 go-librespot[3299]: time="2026-03-15T10:35:16+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:16 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:16 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:17 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:17 smsl-n100 volumio[3286]: info: ----- Volumio3 ---- Mar 15 10:35:17 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:17 smsl-n100 volumio[3286]: info: ----- System startup ---- Mar 15 10:35:17 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:18 smsl-n100 volumio[3286]: info: MYVOLUMIO Environment detected Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Plugin folders cleanup Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning into folder /volumio/app/plugins/ Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category audio_interface Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category miscellanea Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category music_service Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category plugins.json Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category system_controller Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category user_interface Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning into folder /data/plugins/ Mar 15 10:35:18 smsl-n100 volumio[3286]: info: Scanning category music_service Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Plugin folders cleanup completed Mar 15 10:35:19 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:19 smsl-n100 volumio[3286]: info: ----- Core plugins startup ---- Mar 15 10:35:19 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Loading plugins from folder /volumio/app/plugins/ Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin bluetooth to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin multiroom to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin upnp to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin metavolumio to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin airplay_emulation to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin cd_controller to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin raat to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Adding plugin upnp_browser to MyMusic Plugins Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Loading plugins from folder /data/plugins/ Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Loading plugin "system"... Mar 15 10:35:19 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:19 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:19 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Mar 15 10:35:19 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:19 smsl-n100 volumio[3286]: info: Loading plugin "appearance"... Mar 15 10:35:19 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:19 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:19 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:19 smsl-n100 go-librespot[3324]: go-librespot daemon starting... Mar 15 10:35:19 smsl-n100 go-librespot[3324]: time="2026-03-15T10:35:19+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:19 smsl-n100 go-librespot[3324]: time="2026-03-15T10:35:19+01:00" level=debug msg="app state loaded" Mar 15 10:35:19 smsl-n100 go-librespot[3324]: time="2026-03-15T10:35:19+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:19 smsl-n100 go-librespot[3324]: time="2026-03-15T10:35:19+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:19 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:19 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "network"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Refreshing Cached IP Addresses Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "services"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "alsa_controller"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "wizard"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "networkfs"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Starting Udev Watcher for removable devices Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Ignoring mount for partition: boot Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Ignoring mount for partition: volumio Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Ignoring mount for partition: volumio_data Mar 15 10:35:21 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "volumio_command_line_client"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "upnp"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: [1773567321539] Starting Upmpd Daemon Mar 15 10:35:21 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "my_music"... Mar 15 10:35:21 smsl-n100 volumio[3286]: info: Loading plugin "mpd"... Mar 15 10:35:21 smsl-n100 sudo[3346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Mar 15 10:35:21 smsl-n100 sudo[3337]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 15 10:35:21 smsl-n100 sudo[3346]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:21 smsl-n100 sudo[3337]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:21 smsl-n100 sudo[3339]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 15 10:35:21 smsl-n100 sudo[3350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.166/USB /mnt/NAS/USB Mar 15 10:35:21 smsl-n100 sudo[3339]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:21 smsl-n100 sudo[3350]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:21 smsl-n100 sudo[3339]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:21 smsl-n100 sudo[3337]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:21 smsl-n100 kernel: CIFS: Attempting to mount //192.168.0.166/USB Mar 15 10:35:21 smsl-n100 kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 15 10:35:21 smsl-n100 kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 15 10:35:21 smsl-n100 kernel: CIFS VFS: cifs_mount failed w/return code = -101 Mar 15 10:35:21 smsl-n100 sudo[3350]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:22 smsl-n100 volumio[3286]: info: Loading plugin "upnp_browser"... Mar 15 10:35:22 smsl-n100 volumio-remote-updater[506]: [2026-03-15 10:35:22] [connect] Successful connection Mar 15 10:35:22 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:22 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Mar 15 10:35:22 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:22 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:22 smsl-n100 go-librespot[3368]: go-librespot daemon starting... Mar 15 10:35:22 smsl-n100 go-librespot[3368]: time="2026-03-15T10:35:22+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:22 smsl-n100 go-librespot[3368]: time="2026-03-15T10:35:22+01:00" level=debug msg="app state loaded" Mar 15 10:35:22 smsl-n100 go-librespot[3368]: time="2026-03-15T10:35:22+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:22 smsl-n100 go-librespot[3368]: time="2026-03-15T10:35:22+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:22 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:22 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:22 smsl-n100 volumio[3286]: info: Loading plugin "bluetooth"... Mar 15 10:35:23 smsl-n100 volumio[3286]: info: [1773567323168] Starting BluetoothController Mar 15 10:35:23 smsl-n100 volumio[3286]: info: Loading plugin "alarm-clock"... Mar 15 10:35:23 smsl-n100 volumio[3286]: info: Loading plugin "manifestui"... Mar 15 10:35:24 smsl-n100 volumio[3286]: info: Loading plugin "metavolumio"... Mar 15 10:35:24 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:24 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:24 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:25 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:25 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Mar 15 10:35:25 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:25 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:25 smsl-n100 go-librespot[3380]: go-librespot daemon starting... Mar 15 10:35:25 smsl-n100 go-librespot[3380]: time="2026-03-15T10:35:25+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:25 smsl-n100 go-librespot[3380]: time="2026-03-15T10:35:25+01:00" level=debug msg="app state loaded" Mar 15 10:35:25 smsl-n100 go-librespot[3380]: time="2026-03-15T10:35:25+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:25 smsl-n100 go-librespot[3380]: time="2026-03-15T10:35:25+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:25 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:25 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Loading plugin "airplay_emulation"... Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Starting Shairport Sync Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Loading plugin "cd_controller"... Mar 15 10:35:26 smsl-n100 sudo[3346]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Loading plugin "last_100"... Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Loading plugin "raat"... Mar 15 10:35:26 smsl-n100 volumio[3286]: info: RAAT Plugin loaded Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Adding restartRAATSocket REST API Endpoint Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Mar 15 10:35:26 smsl-n100 volumio[3286]: info: Loading plugin "streaming_services"... Mar 15 10:35:28 smsl-n100 volumio[3286]: info: Starting Streaming Service Transparent Proxy Mar 15 10:35:28 smsl-n100 volumio[3286]: info: Loading plugin "tidalconnect"... Mar 15 10:35:28 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:28 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Mar 15 10:35:28 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:28 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:28 smsl-n100 go-librespot[3394]: go-librespot daemon starting... Mar 15 10:35:28 smsl-n100 volumio[3286]: info: Loading plugin "webradio"... Mar 15 10:35:29 smsl-n100 go-librespot[3394]: time="2026-03-15T10:35:28+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:29 smsl-n100 go-librespot[3394]: time="2026-03-15T10:35:29+01:00" level=debug msg="app state loaded" Mar 15 10:35:29 smsl-n100 go-librespot[3394]: time="2026-03-15T10:35:29+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:29 smsl-n100 go-librespot[3394]: time="2026-03-15T10:35:29+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:29 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:29 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:29 smsl-n100 volumio[3286]: info: Loading plugin "i2s_dacs"... Mar 15 10:35:29 smsl-n100 volumio[3286]: info: I2S DAC not set, start Auto-detection Mar 15 10:35:29 smsl-n100 volumio[3286]: info: Loading plugin "volumiodiscovery"... Mar 15 10:35:29 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** For more information see Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 15 10:35:29 smsl-n100 volumio[3286]: *** WARNING *** For more information see Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** For more information see Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** Please fix your application to use the native API of Avahi! Mar 15 10:35:29 smsl-n100 node[3286]: *** WARNING *** For more information see Mar 15 10:35:29 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin volumiodiscovery Mar 15 10:35:29 smsl-n100 volumio[3286]: info: Discovery: Started advertising with name: SMSL N100 Mar 15 10:35:29 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:29 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:29 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 15 10:35:29 smsl-n100 volumio[3286]: info: Loading plugin "spop"... Mar 15 10:35:31 smsl-n100 ntpd[3107]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Mar 15 10:35:31 smsl-n100 volumio[3286]: STREAMING PROXY: Starting server on port 3245 Mar 15 10:35:31 smsl-n100 volumio[3286]: Node JS runtime: 14 Mar 15 10:35:31 smsl-n100 volumio[3286]: info: Loading plugin "multiroom"... Mar 15 10:35:32 smsl-n100 ntpd[3107]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Mar 15 10:35:32 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:32 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Mar 15 10:35:32 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:32 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:32 smsl-n100 go-librespot[3417]: go-librespot daemon starting... Mar 15 10:35:32 smsl-n100 go-librespot[3417]: time="2026-03-15T10:35:32+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:32 smsl-n100 go-librespot[3417]: time="2026-03-15T10:35:32+01:00" level=debug msg="app state loaded" Mar 15 10:35:32 smsl-n100 go-librespot[3417]: time="2026-03-15T10:35:32+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:32 smsl-n100 go-librespot[3417]: time="2026-03-15T10:35:32+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:32 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:32 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:33 smsl-n100 ntpd[3107]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Mar 15 10:35:33 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin multiroom Mar 15 10:35:34 smsl-n100 sudo[3436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Mar 15 10:35:34 smsl-n100 sudo[3436]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:34 smsl-n100 sudo[3436]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:34 smsl-n100 volumio[3286]: /bin/mkdir: cannot create directory ‘/tmp/hls’: File exists Mar 15 10:35:34 smsl-n100 volumio[3286]: info: MRS: MultiRoom plugin initialized Mar 15 10:35:34 smsl-n100 volumio[3286]: info: MRS: STOPPING SNAPCLIENT Mar 15 10:35:34 smsl-n100 volumio[3286]: info: MRS: Snap server stop Mar 15 10:35:34 smsl-n100 sudo[3452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Mar 15 10:35:34 smsl-n100 sudo[3452]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:34 smsl-n100 volumio[3286]: info: MRS: STOPPING volumioStreaming Mar 15 10:35:34 smsl-n100 sudo[3454]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Mar 15 10:35:34 smsl-n100 sudo[3454]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:34 smsl-n100 sudo[3452]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:34 smsl-n100 sudo[3457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Mar 15 10:35:34 smsl-n100 sudo[3457]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:34 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:34 smsl-n100 sudo[3454]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:34 smsl-n100 volumio[3286]: info: Loading plugin "outputs"... Mar 15 10:35:34 smsl-n100 volumio[3286]: info: Loading plugin "albumart"... Mar 15 10:35:34 smsl-n100 sudo[3462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Mar 15 10:35:34 smsl-n100 sudo[3462]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:34 smsl-n100 sudo[3457]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:34 smsl-n100 sudo[3462]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:34 smsl-n100 volumio[3286]: info: Plugin example_plugin is not enabled Mar 15 10:35:34 smsl-n100 volumio[3286]: info: Loading plugin "hi_res_audio"... Mar 15 10:35:34 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:34 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:35 smsl-n100 ntpd[3107]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Mar 15 10:35:35 smsl-n100 volumio[3286]: Forking 3 albumart workers Mar 15 10:35:35 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:35 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Mar 15 10:35:35 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:35 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:35 smsl-n100 go-librespot[3494]: go-librespot daemon starting... Mar 15 10:35:35 smsl-n100 go-librespot[3494]: time="2026-03-15T10:35:35+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:35 smsl-n100 go-librespot[3494]: time="2026-03-15T10:35:35+01:00" level=debug msg="app state loaded" Mar 15 10:35:35 smsl-n100 go-librespot[3494]: time="2026-03-15T10:35:35+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:35 smsl-n100 go-librespot[3494]: time="2026-03-15T10:35:35+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:35 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:35 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:37 smsl-n100 volumio-remote-updater[506]: [2026-03-15 10:35:37] [connect] Successful connection Mar 15 10:35:37 smsl-n100 volumio[3286]: Starting albumart workers Mar 15 10:35:37 smsl-n100 volumio[3286]: Starting albumart workers Mar 15 10:35:37 smsl-n100 volumio[3286]: Starting albumart workers Mar 15 10:35:38 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin hi_res_audio Mar 15 10:35:38 smsl-n100 volumio[3286]: info: Loading plugin "inputs"... Mar 15 10:35:38 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:38 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Mar 15 10:35:38 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:38 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:38 smsl-n100 go-librespot[3512]: go-librespot daemon starting... Mar 15 10:35:39 smsl-n100 go-librespot[3512]: time="2026-03-15T10:35:39+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:39 smsl-n100 go-librespot[3512]: time="2026-03-15T10:35:39+01:00" level=debug msg="app state loaded" Mar 15 10:35:39 smsl-n100 go-librespot[3512]: time="2026-03-15T10:35:39+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:39 smsl-n100 go-librespot[3512]: time="2026-03-15T10:35:39+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:39 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:39 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:39 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:39 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:39 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:39 smsl-n100 volumio[3286]: info: Loading plugin "qobuz"... Mar 15 10:35:41 smsl-n100 volumio[3286]: info: Loading plugin "smart_inputs"... Mar 15 10:35:41 smsl-n100 nmbd[738]: [2026/03/15 10:35:41.681743, 0] ../source3/libsmb/nmblib.c:917(send_udp) Mar 15 10:35:41 smsl-n100 nmbd[738]: Packet send failed to 192.168.0.255(137) ERRNO=Network is unreachable Mar 15 10:35:41 smsl-n100 nmbd[738]: [2026/03/15 10:35:41.682609, 0] ../source3/nmbd/nmbd_packets.c:180(send_netbios_packet) Mar 15 10:35:41 smsl-n100 nmbd[738]: send_netbios_packet: send_packet() to IP 192.168.0.255 port 137 failed Mar 15 10:35:41 smsl-n100 nmbd[738]: [2026/03/15 10:35:41.682960, 0] ../source3/nmbd/nmbd_namequery.c:245(query_name) Mar 15 10:35:41 smsl-n100 nmbd[738]: query_name: Failed to send packet trying to query name WORKGROUP<1d> Mar 15 10:35:42 smsl-n100 volumio[3286]: info: Loading plugin "tidal"... Mar 15 10:35:42 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:42 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Mar 15 10:35:42 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:42 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:42 smsl-n100 go-librespot[3544]: go-librespot daemon starting... Mar 15 10:35:42 smsl-n100 go-librespot[3544]: time="2026-03-15T10:35:42+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:42 smsl-n100 go-librespot[3544]: time="2026-03-15T10:35:42+01:00" level=debug msg="app state loaded" Mar 15 10:35:43 smsl-n100 go-librespot[3544]: time="2026-03-15T10:35:43+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:43 smsl-n100 go-librespot[3544]: time="2026-03-15T10:35:43+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:43 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:43 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:44 smsl-n100 volumio[3286]: info: Loading plugin "oem_helper"... Mar 15 10:35:44 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:44 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:44 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:45 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin oem_helper Mar 15 10:35:45 smsl-n100 volumio[3286]: info: Loading plugin "smslcontrol"... Mar 15 10:35:45 smsl-n100 volumio[3286]: info: Adding this device properties Mar 15 10:35:45 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Mar 15 10:35:45 smsl-n100 volumio[3286]: info: Setting Additional Device Volumio Properties: [object Object] Mar 15 10:35:45 smsl-n100 volumio[3286]: info: Loading plugin "updater_comm"... Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Plugin mpdemulation is not enabled Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Loading plugin "rest_api"... Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Loading plugin "websocket"... Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Starting Socket.io Server version 2.3.0 Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Loading plugin "nowyswiat"... Mar 15 10:35:46 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:46 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Mar 15 10:35:46 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:46 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:46 smsl-n100 go-librespot[3572]: go-librespot daemon starting... Mar 15 10:35:46 smsl-n100 go-librespot[3572]: time="2026-03-15T10:35:46+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:46 smsl-n100 go-librespot[3572]: time="2026-03-15T10:35:46+01:00" level=debug msg="app state loaded" Mar 15 10:35:46 smsl-n100 go-librespot[3572]: time="2026-03-15T10:35:46+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:46 smsl-n100 go-librespot[3572]: time="2026-03-15T10:35:46+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:46 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:46 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin nowyswiat Mar 15 10:35:46 smsl-n100 volumio[3286]: info: [1773567346753] [RadioNowySwiat] API delay: 5 Mar 15 10:35:46 smsl-n100 volumio[3286]: info: [1773567346754] [RadioNowySwiat] Stream 256Kb: http://stream.rcs.revma.com/ypqt40u0x1zuv Mar 15 10:35:46 smsl-n100 volumio[3286]: info: Loading plugin "rad357pl"... Mar 15 10:35:47 smsl-n100 volumio[3286]: info: Applying required configuration parameters for plugin rad357pl Mar 15 10:35:47 smsl-n100 volumio[3286]: info: [1773567347156] [rad357pl] API delay: 5 Mar 15 10:35:47 smsl-n100 volumio[3286]: info: Loading i18n strings for locale pl Mar 15 10:35:47 smsl-n100 volumio[3286]: Updating browse sources language Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::initPlayerControls Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 15 10:35:47 smsl-n100 volumio[3286]: Express server listening on port 3000 Mar 15 10:35:47 smsl-n100 volumio[3286]: [Metrics] WebUI: 31s 101.15ms Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreStateMachine::resetVolumioState Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreStateMachine::getcurrentVolume Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioRetrievevolume Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:47 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:47 smsl-n100 sudo[3589]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 15 10:35:47 smsl-n100 sudo[3589]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:47 smsl-n100 sudo[3589]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:47 smsl-n100 sudo[3591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 15 10:35:47 smsl-n100 sudo[3591]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:47 smsl-n100 volumio[3286]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Mar 15 10:35:47 smsl-n100 volumio[3286]: info: Completed loading Core Plugins Mar 15 10:35:47 smsl-n100 volumio[3286]: info: Preparing to generate the ALSA configuration file Mar 15 10:35:47 smsl-n100 sudo[3591]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:47 smsl-n100 volumio[3286]: info: Volumio Network Manager: Network status updated: 0 Mar 15 10:35:48 smsl-n100 volumio[3286]: info: MRS: Removed streaming files Mar 15 10:35:48 smsl-n100 volumio[3286]: info: MRS: volumioStreaming STOPPED Mar 15 10:35:48 smsl-n100 volumio[3286]: info: MRS: SNAPSERVER STOPPED Mar 15 10:35:48 smsl-n100 volumio[3286]: info: MRS: SNAPCLIENT STOPPED Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Cannot mount NAS USB at system boot, trial number 1 ,retrying in 5 seconds Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Mar 15 10:35:48 smsl-n100 volumio[3286]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Reading ALSA contributions from plugins. Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Reloading queue from file Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreStateMachine::setRepeat false single undefined Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreStateMachine::setRandom false Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Setting Device type: NanoPi NEO 3 Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Asound.conf file unchanged, so no further update is needed Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Output device has changed, restarting MPD Mar 15 10:35:48 smsl-n100 sudo[3599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 15 10:35:48 smsl-n100 sudo[3599]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 sudo[3599]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:48 smsl-n100 sudo[3602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 15 10:35:48 smsl-n100 sudo[3602]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 sudo[3602]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Output device has changed, restarting Shairport Sync Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:48 smsl-n100 sudo[3605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 15 10:35:48 smsl-n100 sudo[3605]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 systemd[1]: Stopping Music Player Daemon... Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 15 10:35:48 smsl-n100 volumio[3286]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 15 10:35:48 smsl-n100 systemd[1]: mpd.service: Succeeded. Mar 15 10:35:48 smsl-n100 systemd[1]: Stopped Music Player Daemon. Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:48 smsl-n100 systemd[1]: Starting Music Player Daemon... Mar 15 10:35:48 smsl-n100 volumio[3286]: info: ___________ START PLUGINS ___________ Mar 15 10:35:48 smsl-n100 volumio[3286]: info: ControllerMpd::onStart: Initializing MPD Mar 15 10:35:48 smsl-n100 volumio[3286]: info: Creating MPD Configuration file Mar 15 10:35:48 smsl-n100 sudo[3615]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Mar 15 10:35:48 smsl-n100 sudo[3615]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 sudo[3615]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 15 10:35:48 smsl-n100 volumio[3286]: info: [1773567348936] CoreMusicLibrary::Adding element Serwery Mediów Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:48 smsl-n100 sudo[3610]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 15 10:35:48 smsl-n100 sudo[3610]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 sudo[3610]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:48 smsl-n100 sudo[3618]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Mar 15 10:35:48 smsl-n100 sudo[3618]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:48 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Mar 15 10:35:49 smsl-n100 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 15 10:35:49 smsl-n100 systemd[1]: mpd.service: Succeeded. Mar 15 10:35:49 smsl-n100 systemd[1]: Stopped Music Player Daemon. Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding METAVOLUMIO REST API Endpoints Mar 15 10:35:49 smsl-n100 systemd[1]: Starting Music Player Daemon... Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:49 smsl-n100 sudo[3623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name SMSL N100 Mar 15 10:35:49 smsl-n100 sudo[3623]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:49 smsl-n100 sudo[3623]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:49 smsl-n100 sudo[3624]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 15 10:35:49 smsl-n100 sudo[3624]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:49 smsl-n100 sudo[3624]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Preparing CD Folders Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding CD REST API Endpoints Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Starting UDEV Watcher for CD Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Detecting CD presence with UDEV Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 15 10:35:49 smsl-n100 volumio[3286]: info: [1773567349350] CoreMusicLibrary::Adding element Last_100 Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Starting RAAT Plugin Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Additional UI Settings Added for plugin music_service/raat Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Registering DSP Elements listener and retrieving current ones Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Additional DSP elements updated Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Updating RAAT Signal Path Mar 15 10:35:49 smsl-n100 volumio[3286]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Streaming services startup Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Starting Streaming Daemon Mar 15 10:35:49 smsl-n100 sudo[3635]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 15 10:35:49 smsl-n100 sudo[3635]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:49 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:49 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Mar 15 10:35:49 smsl-n100 sudo[3635]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:49 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:49 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:49 smsl-n100 go-librespot[3643]: go-librespot daemon starting... Mar 15 10:35:49 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 15 10:35:49 smsl-n100 volumio[3286]: info: [1773567349632] CoreMusicLibrary::Adding element Webradio Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Initializing BBC Radios Mar 15 10:35:49 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:49 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:49 smsl-n100 sudo[3650]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Mar 15 10:35:49 smsl-n100 go-librespot[3643]: time="2026-03-15T10:35:49+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:49 smsl-n100 go-librespot[3643]: time="2026-03-15T10:35:49+01:00" level=debug msg="app state loaded" Mar 15 10:35:49 smsl-n100 sudo[3650]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:49 smsl-n100 go-librespot[3643]: time="2026-03-15T10:35:49+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:49 smsl-n100 go-librespot[3643]: time="2026-03-15T10:35:49+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:49 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:49 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:49 smsl-n100 systemd[1]: Stopping Volumio Tidal Connect Service... Mar 15 10:35:49 smsl-n100 systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Mar 15 10:35:49 smsl-n100 systemd[1]: vtcs.service: Succeeded. Mar 15 10:35:49 smsl-n100 systemd[1]: Stopped Volumio Tidal Connect Service. Mar 15 10:35:49 smsl-n100 sudo[3650]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:49 smsl-n100 volumio[3286]: info: Creating Spotify config file Mar 15 10:35:49 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Mar 15 10:35:50 smsl-n100 volumio[3286]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:50 smsl-n100 volumio[3286]: error: Hi Res Audio Failed Login: Missing Login Data Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Adding HIGHRESAUDIO REST API Endpoints Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Initializing Serial Communication on port /dev/ttyS1 Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Touch Event Listener Process Starting Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Adding inputs REST Endpoints Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Scanning Audio Inputs Mar 15 10:35:50 smsl-n100 sudo[3675]: pam_unix(sudo:auth): conversation failed Mar 15 10:35:50 smsl-n100 sudo[3675]: pam_unix(sudo:auth): auth could not identify password for [volumio] Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Checking against Known Cards name Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Adding Server instance for streaming Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Refreshing TIDAL token Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Initializing GPIOs Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Starting Button Listener Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Turning off Green LED Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Tuning on Blue LED Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Signaling System Ready Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 15 10:35:50 smsl-n100 volumio[3286]: info: [1773567350701] CoreMusicLibrary::Adding element Radio Nowy Swiat Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:50 smsl-n100 volumio[3286]: Cannot find translation for source Radio Nowy Swiat Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Mar 15 10:35:50 smsl-n100 volumio[3286]: info: [1773567350721] CoreMusicLibrary::Adding element RADIO 357 Mar 15 10:35:50 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 10:35:50 smsl-n100 volumio[3286]: Cannot find translation for source Radio Nowy Swiat Mar 15 10:35:50 smsl-n100 volumio[3286]: Cannot find translation for source RADIO 357 Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Volumio Calling Home Mar 15 10:35:50 smsl-n100 volumio[3286]: (node:3286) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Mar 15 10:35:50 smsl-n100 volumio[3286]: (Use `node --trace-deprecation ...` to show where the warning was created) Mar 15 10:35:50 smsl-n100 volumio[3286]: info: Stopping AccessToken refresher cron for QOBUZ Mar 15 10:35:51 smsl-n100 volumio[3286]: info: AccessToken refresher cron started for QOBUZ Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Adding QOBUZ REST API Endpoints Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Mar 15 10:35:51 smsl-n100 volumio[3286]: Unhandled rejection Error: No sockets available, cannot start. Mar 15 10:35:51 smsl-n100 volumio[3286]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Mar 15 10:35:51 smsl-n100 volumio[3286]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Mar 15 10:35:51 smsl-n100 volumio[3286]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Mar 15 10:35:51 smsl-n100 volumio[3286]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Mar 15 10:35:51 smsl-n100 volumio[3286]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Mar 15 10:35:51 smsl-n100 volumio[3286]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Mar 15 10:35:51 smsl-n100 volumio[3286]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Mar 15 10:35:51 smsl-n100 volumio[3286]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Mar 15 10:35:51 smsl-n100 volumio[3286]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Mar 15 10:35:51 smsl-n100 volumio[3286]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Mar 15 10:35:51 smsl-n100 volumio[3286]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Mar 15 10:35:51 smsl-n100 volumio[3286]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Mar 15 10:35:51 smsl-n100 volumio[3286]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Mar 15 10:35:51 smsl-n100 volumio[3286]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Mar 15 10:35:51 smsl-n100 volumio[3286]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Mar 15 10:35:51 smsl-n100 volumio[3286]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 15 10:35:51 smsl-n100 volumio[3286]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Serial port opened successfully Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Sending serial start messages Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Reporting MCU Network Status: 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: error: No access token received for TIDAL Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Touch Event Listener Process Closed Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Cannot start Volumio Streaming Daemon Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 15 10:35:51 smsl-n100 volumio[3286]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'SMSL N100' Mar 15 10:35:51 smsl-n100 volumio[3286]: Can't get device info: No such device Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MPD Permissions set Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MPD Permissions set Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Upmpdcli Daemon Started Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Setting Device Volume Override Mar 15 10:35:51 smsl-n100 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Mar 15 10:35:51 smsl-n100 systemd[1]: mpd.service: Failed with result 'protocol'. Mar 15 10:35:51 smsl-n100 systemd[1]: Failed to start Music Player Daemon. Mar 15 10:35:51 smsl-n100 sudo[3618]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 15 10:35:51 smsl-n100 sudo[3605]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Updating Volume Controller Parameters: Device: 5 Name: SMSL USB AUDIO Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Disabling external Volume Control Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:51 smsl-n100 systemd[1]: Starting Music Player Daemon... Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Spotify config file written Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:51 smsl-n100 sudo[3697]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Mar 15 10:35:51 smsl-n100 sudo[3697]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:51 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 0, message: undefined Mar 15 10:35:51 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:51 smsl-n100 sudo[3695]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Mar 15 10:35:51 smsl-n100 sudo[3695]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:51 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:51 smsl-n100 sudo[3695]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:51 smsl-n100 sudo[3697]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:51 smsl-n100 go-librespot[3699]: go-librespot daemon starting... Mar 15 10:35:51 smsl-n100 volumio[3286]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Mar 15 10:35:51 smsl-n100 volumio[3286]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Mar 15 10:35:51 smsl-n100 volumio[3286]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Mar 15 10:35:51 smsl-n100 volumio[3286]: See "systemctl status mpd.service" and "journalctl -xe" for details. Mar 15 10:35:51 smsl-n100 go-librespot[3699]: time="2026-03-15T10:35:51+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:51 smsl-n100 volumio[3286]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service Mar 15 10:35:51 smsl-n100 volumio[3286]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. Mar 15 10:35:51 smsl-n100 volumio[3286]: See "systemctl status mpd.service" and "journalctl -xe" for details. Mar 15 10:35:51 smsl-n100 go-librespot[3699]: time="2026-03-15T10:35:51+01:00" level=debug msg="app state loaded" Mar 15 10:35:51 smsl-n100 go-librespot[3699]: time="2026-03-15T10:35:51+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:51 smsl-n100 go-librespot[3699]: time="2026-03-15T10:35:51+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:51 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:51 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:35:52 smsl-n100 volumio[3286]: info: No need to fix Spotify hosts Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:52 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:52 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:52 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:52 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:52 smsl-n100 volumio[3286]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Mar 15 10:35:52 smsl-n100 volumio-remote-updater[506]: [2026-03-15 10:35:52] [connect] Successful connection Mar 15 10:35:52 smsl-n100 sudo[3721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Mar 15 10:35:52 smsl-n100 sudo[3721]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:52 smsl-n100 sudo[3721]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:52 smsl-n100 volumio-remote-updater[506]: [2026-03-15 10:35:52] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1773567352 101 Mar 15 10:35:52 smsl-n100 volumio[3286]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Mar 15 10:35:52 smsl-n100 volumio[3286]: info: Volumio BT Module successfully started Mar 15 10:35:52 smsl-n100 volumio[3286]: info: Starting Shairport Sync Mar 15 10:35:52 smsl-n100 volumio[3286]: info: Starting Shairport Sync Mar 15 10:35:52 smsl-n100 volumio[3286]: info: Starting Shairport Sync Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:52 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioGetState Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioGetState Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:53 smsl-n100 volumio[3286]: info: TidalConnect service stoped! Mar 15 10:35:53 smsl-n100 volumio[3286]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Mar 15 10:35:53 smsl-n100 volumio[3286]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:53 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Help! Some callbacks for volumioPushState are crashing! Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Cannot read property 'sendVolumeMute' of undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: MAXVOL, message: Mar 15 10:35:53 smsl-n100 volumio[3286]: error: Serial API: Failed to decode command: 100, message: undefined Mar 15 10:35:53 smsl-n100 volumio[3286]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Mar 15 10:35:53 smsl-n100 sudo[3724]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 15 10:35:53 smsl-n100 sudo[3724]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:53 smsl-n100 sudo[3728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 15 10:35:53 smsl-n100 sudo[3726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 15 10:35:53 smsl-n100 sudo[3726]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:53 smsl-n100 sudo[3730]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.166/USB /mnt/NAS/USB Mar 15 10:35:53 smsl-n100 sudo[3728]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:53 smsl-n100 sudo[3730]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:53 smsl-n100 sudo[3744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Mar 15 10:35:53 smsl-n100 sudo[3744]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:53 smsl-n100 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 15 10:35:53 smsl-n100 kernel: CIFS: Attempting to mount //192.168.0.166/USB Mar 15 10:35:53 smsl-n100 kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 15 10:35:53 smsl-n100 kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 15 10:35:54 smsl-n100 kernel: CIFS VFS: cifs_mount failed w/return code = -101 Mar 15 10:35:53 smsl-n100 sudo[3730]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:53 smsl-n100 systemd[1]: shairport-sync.service: Succeeded. Mar 15 10:35:54 smsl-n100 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 15 10:35:54 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 15 10:35:54 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 15 10:35:54 smsl-n100 volumio[3286]: info: Cannot mount NAS USB at system boot, trial number 2 ,retrying in 5 seconds Mar 15 10:35:54 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 15 10:35:54 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 15 10:35:54 smsl-n100 systemd[1]: Started Volumio Tidal Connect Service. Mar 15 10:35:54 smsl-n100 sudo[3744]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:54 smsl-n100 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 15 10:35:54 smsl-n100 sudo[3728]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:54 smsl-n100 sudo[3724]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:54 smsl-n100 sudo[3726]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:54 smsl-n100 volumio[3286]: info: Shairport-Sync Started Mar 15 10:35:54 smsl-n100 volumio[3286]: Error adding Membership: Error: addMembership EINVAL Mar 15 10:35:54 smsl-n100 volumio[3286]: info: Shairport-Sync Started Mar 15 10:35:54 smsl-n100 volumio[3286]: info: Shairport-Sync Started Mar 15 10:35:54 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:54 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:54 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:35:54 smsl-n100 volumio[3286]: info: Executing endpoint tc_getconfig Mar 15 10:35:54 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Mar 15 10:35:54 smsl-n100 vtcs[3762]: STARTING TidalConnect services, version: 1.4.0.34 Mar 15 10:35:55 smsl-n100 vtcs[3762]: STARTED TidalConnect services. Mar 15 10:35:55 smsl-n100 volumio[3286]: info: Executing endpoint tc_connect Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Mar 15 10:35:55 smsl-n100 volumio[3286]: info: Connecting to TidalConnect Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreCommandRouter::servicePushState Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:55 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:55 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Mar 15 10:35:55 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:55 smsl-n100 volumio[3286]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreCommandRouter::servicePushState Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreStateMachine::pushState Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioPushState Mar 15 10:35:55 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:55 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:35:55 smsl-n100 volumio[3286]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received tidalconnect Mar 15 10:35:55 smsl-n100 volumio[3286]: info: MRS: Getting audio outputs on start Mar 15 10:35:55 smsl-n100 volumio[3286]: info: MRS: Requesting all other devices output Mar 15 10:35:55 smsl-n100 go-librespot[3788]: go-librespot daemon starting... Mar 15 10:35:55 smsl-n100 go-librespot[3788]: time="2026-03-15T10:35:55+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:55 smsl-n100 go-librespot[3788]: time="2026-03-15T10:35:55+01:00" level=debug msg="app state loaded" Mar 15 10:35:55 smsl-n100 go-librespot[3788]: time="2026-03-15T10:35:55+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:55 smsl-n100 go-librespot[3788]: time="2026-03-15T10:35:55+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:55 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:55 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:55 smsl-n100 volumio[3286]: info: go-librespot daemon successfully initialized Mar 15 10:35:56 smsl-n100 mpd[3701]: Mar 15 10:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Mar 15 10:35:56 smsl-n100 systemd[1]: Started Music Player Daemon. Mar 15 10:35:56 smsl-n100 mpd_monitor.sh[510]: MPD restarted due to no mpc output. Mar 15 10:35:56 smsl-n100 volumio[3286]: error: MPD error: The expression evaluated to a falsy value: Mar 15 10:35:56 smsl-n100 volumio[3286]: assert.ok(self.idling) Mar 15 10:35:56 smsl-n100 volumio[3286]: error: The expression evaluated to a falsy value: Mar 15 10:35:56 smsl-n100 volumio[3286]: assert.ok(self.idling) Mar 15 10:35:56 smsl-n100 volumio[3286]: error: updateQueue error: null Mar 15 10:35:57 smsl-n100 volumio[3286]: info: TidalConnect service started! Mar 15 10:35:57 smsl-n100 volumio[3286]: info: Completed starting Core Plugins Mar 15 10:35:57 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:57 smsl-n100 volumio[3286]: info: ----- MyVolumio plugins startup ---- Mar 15 10:35:57 smsl-n100 volumio[3286]: info: ------------------------------------------- Mar 15 10:35:57 smsl-n100 volumio[3286]: info: [MyVolumio PluginManager] Fetching plans data.... Mar 15 10:35:58 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:35:58 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Mar 15 10:35:58 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:35:58 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:35:58 smsl-n100 go-librespot[3838]: go-librespot daemon starting... Mar 15 10:35:58 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:35:58 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:35:58 smsl-n100 go-librespot[3838]: time="2026-03-15T10:35:58+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:35:58 smsl-n100 go-librespot[3838]: time="2026-03-15T10:35:58+01:00" level=debug msg="app state loaded" Mar 15 10:35:58 smsl-n100 go-librespot[3838]: time="2026-03-15T10:35:58+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:35:58 smsl-n100 go-librespot[3838]: time="2026-03-15T10:35:58+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:35:58 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:35:58 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:35:59 smsl-n100 sudo[3846]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.166/USB /mnt/NAS/USB Mar 15 10:35:59 smsl-n100 sudo[3846]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:35:59 smsl-n100 kernel: CIFS: Attempting to mount //192.168.0.166/USB Mar 15 10:35:59 smsl-n100 kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 15 10:35:59 smsl-n100 kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 15 10:35:59 smsl-n100 kernel: CIFS VFS: cifs_mount failed w/return code = -101 Mar 15 10:35:59 smsl-n100 sudo[3846]: pam_unix(sudo:session): session closed for user root Mar 15 10:35:59 smsl-n100 volumio[3286]: info: Cannot mount NAS USB at system boot, trial number 3 ,retrying in 5 seconds Mar 15 10:35:59 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:35:59 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:35:59 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:36:01 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:01 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:01 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:01 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Mar 15 10:36:01 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:01 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:01 smsl-n100 volumio[3286]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo3&variante=smsl&version=3.789&uuid=e90348cd91cc07954eb7fc2f88f432e3" http://updates.volumio.org/downloader-v1/track-device Mar 15 10:36:01 smsl-n100 volumio[3286]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 15 10:36:01 smsl-n100 volumio[3286]: Dload Upload Total Spent Left Speed Mar 15 10:36:01 smsl-n100 volumio[3286]: [132B blob data] Mar 15 10:36:01 smsl-n100 volumio[3286]: retrying in 5 seconds, trial 0 Mar 15 10:36:01 smsl-n100 volumio[3286]: info: Volumio Calling Home Mar 15 10:36:01 smsl-n100 go-librespot[3855]: go-librespot daemon starting... Mar 15 10:36:01 smsl-n100 go-librespot[3855]: time="2026-03-15T10:36:01+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:01 smsl-n100 go-librespot[3855]: time="2026-03-15T10:36:01+01:00" level=debug msg="app state loaded" Mar 15 10:36:01 smsl-n100 go-librespot[3855]: time="2026-03-15T10:36:01+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:01 smsl-n100 go-librespot[3855]: time="2026-03-15T10:36:01+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:01 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:01 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:01 smsl-n100 volumio[3286]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Mar 15 10:36:04 smsl-n100 sudo[3871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.166/USB /mnt/NAS/USB Mar 15 10:36:04 smsl-n100 sudo[3871]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:36:04 smsl-n100 kernel: CIFS: Attempting to mount //192.168.0.166/USB Mar 15 10:36:04 smsl-n100 kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 15 10:36:04 smsl-n100 kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 15 10:36:04 smsl-n100 kernel: CIFS VFS: cifs_mount failed w/return code = -101 Mar 15 10:36:04 smsl-n100 sudo[3871]: pam_unix(sudo:session): session closed for user root Mar 15 10:36:04 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:04 smsl-n100 volumio[3286]: info: Cannot mount NAS USB at system boot, trial number 4 ,retrying in 5 seconds Mar 15 10:36:04 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:04 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:36:04 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:36:04 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:36:04 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:04 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Mar 15 10:36:04 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:04 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:04 smsl-n100 go-librespot[3890]: go-librespot daemon starting... Mar 15 10:36:04 smsl-n100 go-librespot[3890]: time="2026-03-15T10:36:04+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:04 smsl-n100 go-librespot[3890]: time="2026-03-15T10:36:04+01:00" level=debug msg="app state loaded" Mar 15 10:36:04 smsl-n100 go-librespot[3890]: time="2026-03-15T10:36:04+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:04 smsl-n100 go-librespot[3890]: time="2026-03-15T10:36:04+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:04 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:04 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:07 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:07 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:08 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:08 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Mar 15 10:36:08 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:08 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:08 smsl-n100 go-librespot[3901]: go-librespot daemon starting... Mar 15 10:36:08 smsl-n100 go-librespot[3901]: time="2026-03-15T10:36:08+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:08 smsl-n100 go-librespot[3901]: time="2026-03-15T10:36:08+01:00" level=debug msg="app state loaded" Mar 15 10:36:08 smsl-n100 go-librespot[3901]: time="2026-03-15T10:36:08+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:08 smsl-n100 go-librespot[3901]: time="2026-03-15T10:36:08+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:08 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:08 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:09 smsl-n100 sudo[3909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.0.166/USB /mnt/NAS/USB Mar 15 10:36:09 smsl-n100 sudo[3909]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 10:36:09 smsl-n100 kernel: CIFS: Attempting to mount //192.168.0.166/USB Mar 15 10:36:09 smsl-n100 kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. Mar 15 10:36:09 smsl-n100 kernel: CIFS VFS: Error connecting to socket. Aborting operation. Mar 15 10:36:09 smsl-n100 kernel: CIFS VFS: cifs_mount failed w/return code = -101 Mar 15 10:36:09 smsl-n100 sudo[3909]: pam_unix(sudo:session): session closed for user root Mar 15 10:36:09 smsl-n100 volumio[3286]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Mar 15 10:36:09 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:36:09 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:36:09 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:36:10 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:10 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:11 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:11 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Mar 15 10:36:11 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:11 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:11 smsl-n100 go-librespot[3918]: go-librespot daemon starting... Mar 15 10:36:11 smsl-n100 go-librespot[3918]: time="2026-03-15T10:36:11+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:11 smsl-n100 go-librespot[3918]: time="2026-03-15T10:36:11+01:00" level=debug msg="app state loaded" Mar 15 10:36:11 smsl-n100 go-librespot[3918]: time="2026-03-15T10:36:11+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:11 smsl-n100 go-librespot[3918]: time="2026-03-15T10:36:11+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:11 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:11 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:11 smsl-n100 volumio[3286]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo3&variante=smsl&version=3.789&uuid=e90348cd91cc07954eb7fc2f88f432e3" http://updates.volumio.org/downloader-v1/track-device Mar 15 10:36:11 smsl-n100 volumio[3286]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 15 10:36:11 smsl-n100 volumio[3286]: Dload Upload Total Spent Left Speed Mar 15 10:36:11 smsl-n100 volumio[3286]: [132B blob data] Mar 15 10:36:11 smsl-n100 volumio[3286]: retrying in 5 seconds, trial 1 Mar 15 10:36:11 smsl-n100 volumio[3286]: info: Volumio Calling Home Mar 15 10:36:13 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:13 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:14 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:14 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Mar 15 10:36:14 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:14 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:14 smsl-n100 go-librespot[3933]: go-librespot daemon starting... Mar 15 10:36:14 smsl-n100 go-librespot[3933]: time="2026-03-15T10:36:14+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:14 smsl-n100 go-librespot[3933]: time="2026-03-15T10:36:14+01:00" level=debug msg="app state loaded" Mar 15 10:36:14 smsl-n100 kernel: rk_gmac-dwmac ff540000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx Mar 15 10:36:14 smsl-n100 ifplugd(eth0)[755]: Link beat detected. Mar 15 10:36:14 smsl-n100 dhcpcd[564]: eth0: carrier acquired Mar 15 10:36:14 smsl-n100 go-librespot[3933]: time="2026-03-15T10:36:14+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:14 smsl-n100 go-librespot[3933]: time="2026-03-15T10:36:14+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:14 smsl-n100 dhcpcd[564]: eth0: IAID 79:a6:a5:22 Mar 15 10:36:14 smsl-n100 dhcpcd[564]: eth0: adding address fe80::5c96:79ff:fea6:a522 Mar 15 10:36:14 smsl-n100 dhcpcd[564]: ipv6_addaddr1: Permission denied Mar 15 10:36:14 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:14 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:14 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:36:14 smsl-n100 ifplugd(eth0)[755]: Executing '/etc/ifplugd/ifplugd.action eth0 up'. Mar 15 10:36:14 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:36:14 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:36:15 smsl-n100 dhcpcd[564]: eth0: soliciting an IPv6 router Mar 15 10:36:15 smsl-n100 ifplugd(eth0)[755]: client: sending commands to master dhcpcd process Mar 15 10:36:15 smsl-n100 dhcpcd[3977]: sending commands to master dhcpcd process Mar 15 10:36:15 smsl-n100 dhcpcd[564]: control command: /sbin/dhcpcd eth0 Mar 15 10:36:15 smsl-n100 ifplugd(eth0)[755]: Program executed successfully. Mar 15 10:36:15 smsl-n100 dhcpcd[564]: eth0: soliciting a DHCP lease Mar 15 10:36:15 smsl-n100 dhcpcd[564]: eth0: offered 192.168.1.74 from 192.168.1.1 Mar 15 10:36:15 smsl-n100 dhcpcd[564]: eth0: probing address 192.168.1.74/24 Mar 15 10:36:16 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:16 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:17 smsl-n100 volumio[3286]: error: MyVolumio Plugin failed to start in a timely fashion Mar 15 10:36:17 smsl-n100 volumio[3286]: [Metrics] CommandRouter: 59s 678.21ms Mar 15 10:36:17 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumiosetStartupVolume Mar 15 10:36:17 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 15 10:36:17 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:36:17 smsl-n100 volumio[3286]: info: CoreCommandRouter::Close All Modals sent Mar 15 10:36:17 smsl-n100 volumio[3286]: info: CoreCommandRouter::Close All Modals sent Mar 15 10:36:18 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:18 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Mar 15 10:36:18 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:18 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:18 smsl-n100 go-librespot[4007]: go-librespot daemon starting... Mar 15 10:36:18 smsl-n100 go-librespot[4007]: time="2026-03-15T10:36:18+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:18 smsl-n100 go-librespot[4007]: time="2026-03-15T10:36:18+01:00" level=debug msg="app state loaded" Mar 15 10:36:18 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 15 10:36:18 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 15 10:36:18 smsl-n100 go-librespot[4007]: time="2026-03-15T10:36:18+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:18 smsl-n100 go-librespot[4007]: time="2026-03-15T10:36:18+01:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Mar 15 10:36:18 smsl-n100 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 15 10:36:18 smsl-n100 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 15 10:36:18 smsl-n100 volumio[3286]: xcb_connection_has_error() returned true Mar 15 10:36:18 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 15 10:36:19 smsl-n100 volumio[3286]: info: Initializing connection to go-librespot Websocket Mar 15 10:36:19 smsl-n100 volumio[3286]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 15 10:36:19 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Fetching time from Volumio... Mar 15 10:36:20 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Date not found in response Mar 15 10:36:20 smsl-n100 volumio-time-update[504]: volumio-time-update-util: Retrying in 5 seconds... Mar 15 10:36:20 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 15 10:36:20 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 15 10:36:20 smsl-n100 volumio[3286]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 15 10:36:21 smsl-n100 dhcpcd[564]: eth0: leased 192.168.1.74 for 86400 seconds Mar 15 10:36:21 smsl-n100 dhcpcd[564]: eth0: adding route to 192.168.1.0/24 Mar 15 10:36:21 smsl-n100 dhcpcd[564]: eth0: adding default route via 192.168.1.1 Mar 15 10:36:21 smsl-n100 avahi-daemon[505]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.1.74. Mar 15 10:36:21 smsl-n100 avahi-daemon[505]: New relevant interface eth0.IPv4 for mDNS. Mar 15 10:36:21 smsl-n100 avahi-daemon[505]: Registering new address record for 192.168.1.74 on eth0.IPv4. Mar 15 10:36:21 smsl-n100 systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 15 10:36:21 smsl-n100 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Mar 15 10:36:21 smsl-n100 systemd[1]: Stopped go-librespot Daemon. Mar 15 10:36:21 smsl-n100 systemd[1]: Started go-librespot Daemon. Mar 15 10:36:21 smsl-n100 go-librespot[4045]: go-librespot daemon starting... Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=info msg="running go-librespot 0.4.0" Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=debug msg="app state loaded" Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=info msg="api server listening on 127.0.0.1:9879" Mar 15 10:36:21 smsl-n100 volumio[3286]: info: MRS: Found cast device: PLAY-TV-BOX-4A-d1805892cb0f0bb95a30afc34de49c0b Mar 15 10:36:21 smsl-n100 volumio[3286]: info: Adding audio output: Mar 15 10:36:21 smsl-n100 ntpd[3107]: ntpd exiting on signal 15 (Terminated) Mar 15 10:36:21 smsl-n100 systemd[1]: Stopping Network Time Service... Mar 15 10:36:21 smsl-n100 systemd[1]: ntp.service: Succeeded. Mar 15 10:36:21 smsl-n100 systemd[1]: Stopped Network Time Service. Mar 15 10:36:21 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 15 10:36:21 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 15 10:36:21 smsl-n100 systemd[1]: Starting Network Time Service... Mar 15 10:36:21 smsl-n100 volumio[3286]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 15 10:36:21 smsl-n100 ntpd[4067]: ntpd 4.2.8p12@1.3728-o (1): Starting Mar 15 10:36:21 smsl-n100 ntpd[4067]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Mar 15 10:36:21 smsl-n100 systemd[1]: Started Network Time Service. Mar 15 10:36:21 smsl-n100 ntpd[4073]: proto: precision = 1.166 usec (-20) Mar 15 10:36:21 smsl-n100 ntpd[4073]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Mar 15 10:36:21 smsl-n100 ntpd[4073]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Mar 15 10:36:21 smsl-n100 ntpd[4073]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 1174 days ago Mar 15 10:36:21 smsl-n100 ntpd[4073]: Listen and drop on 0 v6wildcard [::]:123 Mar 15 10:36:21 smsl-n100 ntpd[4073]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Mar 15 10:36:21 smsl-n100 ntpd[4073]: Listen normally on 2 lo 127.0.0.1:123 Mar 15 10:36:21 smsl-n100 ntpd[4073]: Listen normally on 3 eth0 192.168.1.74:123 Mar 15 10:36:21 smsl-n100 ntpd[4073]: Listening on routing socket on fd #20 for interface updates Mar 15 10:36:21 smsl-n100 ntpd[4073]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Mar 15 10:36:21 smsl-n100 ntpd[4073]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Mar 15 10:36:21 smsl-n100 volumio[3286]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=nanopineo3&variante=smsl&version=3.789&uuid=e90348cd91cc07954eb7fc2f88f432e3" http://updates.volumio.org/downloader-v1/track-device Mar 15 10:36:21 smsl-n100 volumio[3286]: % Total % Received % Xferd Average Speed Time Time Time Current Mar 15 10:36:21 smsl-n100 volumio[3286]: Dload Upload Total Spent Left Speed Mar 15 10:36:21 smsl-n100 volumio[3286]: [132B blob data] Mar 15 10:36:21 smsl-n100 volumio[3286]: retrying in 5 seconds, trial 2 Mar 15 10:36:21 smsl-n100 volumio[3286]: info: Volumio Calling Home Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 15 10:36:21 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:21+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=info msg="zeroconf server listening on port 38277" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="obtained new client token: AACkclSu5cQvFghCCy2B6JntzWBs2YRK28rtAxz8WKYBgDcGT8iVkd7G+nfHJZhHoIUg6AvxP9pvbhbwXyrA0rFNOz1xRWTNouTVDefAGADiE0BMFiGGTRwio3n7G0l3Xg14Rk8Vk02Elf+224mIMleMoXlC3tqFGtNOJ5MK757tIP5klKsc/WYBDMlHDnENpGcGs1g40ev/P+VNMbmZ+fUgOVXD/3gDcq6hyBfn6nuEPieJHo4U3A==" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Mar 15 10:36:22 smsl-n100 volumio[3286]: info: Discovery: adding fb74965d-62a3-4ccc-a848-f15079eef8e5 Mar 15 10:36:22 smsl-n100 volumio[3286]: info: Discovery: Found device SMSL N100 Mar 15 10:36:22 smsl-n100 volumio[3286]: info: CoreCommandRouter::volumioGetState Mar 15 10:36:22 smsl-n100 volumio[3286]: info: CorePlayQueue::getTrack 0 Mar 15 10:36:22 smsl-n100 volumio[3286]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 15 10:36:22 smsl-n100 volumio[3286]: Error: The value NaN is not a number Mar 15 10:36:22 smsl-n100 volumio[3286]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Mar 15 10:36:22 smsl-n100 volumio[3286]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Mar 15 10:36:22 smsl-n100 volumio[3286]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) Mar 15 10:36:22 smsl-n100 volumio[3286]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Mar 15 10:36:22 smsl-n100 volumio[3286]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Mar 15 10:36:22 smsl-n100 volumio[3286]: at Browser.emit (events.js:400:28) Mar 15 10:36:22 smsl-n100 volumio[3286]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Mar 15 10:36:22 smsl-n100 volumio[3286]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Mar 15 10:36:22 smsl-n100 volumio[3286]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Mar 15 10:36:22 smsl-n100 volumio[3286]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Mar 15 10:36:22 smsl-n100 volumio[3286]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Mar 15 10:36:22 smsl-n100 volumio[3286]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Mar 15 10:36:22 smsl-n100 volumio[3286]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Mar 15 10:36:22 smsl-n100 volumio[3286]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="completed keyexchange" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="completed challenge" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=info msg="authenticated AP" username="cz**********ki" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=info msg="authenticated Login5" username="cz**********ki" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="initializing zeroconf session" username="cz**********ki" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="dealer connection opened" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=trace msg="starting accesspoint recv loop" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=trace msg="starting dealer recv loop" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=trace msg="received accesspoint ping" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="received connection id: MGY4ZDgyZTAtNjlm...ODAwNkJCNUZDOQ==" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=trace msg="received accesspoint pong ack" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="skipping dealer message" uri="ap://product-state-update" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="put connect state because NEW_DEVICE" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="update volume requested to 65535/65535" Mar 15 10:36:22 smsl-n100 ntpd[4073]: Soliciting pool server 194.92.94.32 Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 15 10:36:22 smsl-n100 go-librespot[4045]: time="2026-03-15T10:36:22+01:00" level=trace msg="emitting websocket event: volume" Mar 15 10:36:23 smsl-n100 sudo[4089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-03-15 10:35 Mar 15 10:36:23 smsl-n100 sudo[4089]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="723ba1d50268911818ebdca474fb7656df6050cb" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="smsl" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 14 Feb 2025 02:46:15 PM CET" VOLUMIO_VERSION="3.789" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR_MODEL="SMSL S100" VOLUMIO_VENDOR="SMSL" VOLUMIO_MODEL="S100" VOLUMIO_HASH="215d731aee688e00fb3cc923952be9a7"