-- Logs begin at Thu 2019-02-14 08:11:59 -02, end at Thu 2025-04-17 10:45:30 -03. -- Apr 17 10:44:00 volumio volumio[893]: info: Loading plugin "ytmusic"... Apr 17 10:44:04 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:04 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:04 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:06 volumio volumio-remote-updater[487]: [2025-04-17 10:44:06] [connect] Successful connection Apr 17 10:44:07 volumio volumio[893]: info: Loading plugin "outputs"... Apr 17 10:44:07 volumio volumio[893]: info: Loading plugin "albumart"... Apr 17 10:44:07 volumio volumio[893]: info: Plugin example_plugin is not enabled Apr 17 10:44:07 volumio volumio[893]: info: Loading plugin "inputs"... Apr 17 10:44:07 volumio volumio[893]: info: Loading plugin "updater_comm"... Apr 17 10:44:08 volumio volumio[893]: info: Plugin mpdemulation is not enabled Apr 17 10:44:08 volumio volumio[893]: info: Loading plugin "rest_api"... Apr 17 10:44:08 volumio volumio[893]: info: Loading plugin "websocket"... Apr 17 10:44:08 volumio volumio[893]: info: Starting Socket.io Server version 2.3.0 Apr 17 10:44:08 volumio volumio[893]: info: Loading plugin "lastfm"... Apr 17 10:44:08 volumio volumio[893]: Forking 3 albumart workers Apr 17 10:44:09 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:09 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:09 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:10 volumio volumio[893]: info: Loading i18n strings for locale pt Apr 17 10:44:10 volumio volumio[893]: Updating browse sources language Apr 17 10:44:10 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:10 volumio volumio[893]: Starting albumart workers Apr 17 10:44:10 volumio volumio[893]: Starting albumart workers Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::initPlayerControls Apr 17 10:44:11 volumio volumio[893]: Starting albumart workers Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:11 volumio volumio[893]: Express server listening on port 3000 Apr 17 10:44:11 volumio volumio[893]: [Metrics] WebUI: 28s 960.28ms Apr 17 10:44:11 volumio volumio[893]: info: CoreStateMachine::resetVolumioState Apr 17 10:44:11 volumio volumio[893]: info: CoreStateMachine::getcurrentVolume Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:11 volumio sudo[1079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 17 10:44:11 volumio sudo[1079]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:11 volumio sudo[1081]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 17 10:44:11 volumio sudo[1079]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:11 volumio sudo[1081]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:11 volumio volumio[893]: info: Volumio Network Manager: Network status updated: 0 Apr 17 10:44:11 volumio sudo[1081]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:11 volumio volumio[893]: info: CoreStateMachine::pushState Apr 17 10:44:11 volumio volumio[893]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:11 volumio volumio[893]: info: CoreStateMachine::updateTrackBlock Apr 17 10:44:11 volumio volumio[893]: info: CorePlayQueue::getTrackBlock Apr 17 10:44:11 volumio volumio[893]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:44:12 volumio volumio[893]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 17 10:44:12 volumio volumio[893]: info: CoreStateMachine::pushState Apr 17 10:44:12 volumio volumio[893]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:12 volumio volumio[893]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:12 volumio volumio[893]: info: Reloading queue from file Apr 17 10:44:12 volumio volumio[893]: info: CoreStateMachine::setRepeat null single undefined Apr 17 10:44:12 volumio volumio[893]: info: CoreStateMachine::pushState Apr 17 10:44:12 volumio volumio[893]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:12 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:44:12 volumio volumio[893]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:12 volumio volumio[893]: info: CoreStateMachine::setRandom null Apr 17 10:44:12 volumio volumio[893]: info: CoreStateMachine::pushState Apr 17 10:44:12 volumio volumio[893]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:12 volumio volumio[893]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:12 volumio volumio[893]: info: Setting Device type: Raspberry PI Apr 17 10:44:12 volumio sudo[1111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 17 10:44:12 volumio sudo[1111]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:12 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Apr 17 10:44:12 volumio sudo[1111]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:12 volumio volumio[893]: info: Completed loading Core Plugins Apr 17 10:44:12 volumio volumio[893]: info: Preparing to generate the ALSA configuration file Apr 17 10:44:12 volumio volumio[893]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 17 10:44:12 volumio volumio[893]: info: Reading ALSA contributions from plugins. Apr 17 10:44:12 volumio volumio[893]: info: Upmpdcli Daemon Started Apr 17 10:44:12 volumio volumio[893]: info: Asound.conf file unchanged, so no further update is needed Apr 17 10:44:12 volumio volumio[893]: info: Output device has changed, restarting MPD Apr 17 10:44:13 volumio volumio[893]: info: Output device has changed, restarting Shairport Sync Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:13 volumio sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:44:13 volumio sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:13 volumio sudo[1122]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:13 volumio sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:44:13 volumio sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:13 volumio systemd[1]: Stopping Music Player Daemon... Apr 17 10:44:13 volumio volumio[893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:13 volumio volumio[893]: info: ___________ START PLUGINS ___________ Apr 17 10:44:13 volumio volumio[893]: info: ControllerMpd::onStart: Initializing MPD Apr 17 10:44:13 volumio volumio[893]: info: Creating MPD Configuration file Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:13 volumio volumio[893]: info: [1744897453308] CoreMusicLibrary::Adding element Servidores multimédia Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:13 volumio sudo[1134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:44:13 volumio sudo[1134]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:13 volumio sudo[1134]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:13 volumio sudo[1136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:44:13 volumio sudo[1136]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:13 volumio volumio[893]: info: [1744897453617] CoreMusicLibrary::Adding element Last_100 Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:13 volumio volumio[893]: info: [1744897453625] CoreMusicLibrary::Adding element Webradio Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:44:13 volumio volumio[893]: info: Initializing BBC Radios Apr 17 10:44:13 volumio systemd[1]: mpd.service: Succeeded. Apr 17 10:44:13 volumio systemd[1]: Stopped Music Player Daemon. Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:13 volumio volumio[893]: info: [1744897453836] CoreMusicLibrary::Adding element Bandcamp Discover Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:13 volumio volumio[893]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:13 volumio systemd[1]: Starting Music Player Daemon... Apr 17 10:44:13 volumio volumio[893]: info: Creating Spotify config file Apr 17 10:44:13 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:14 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:14 volumio volumio[893]: info: [1744897454049] CoreMusicLibrary::Adding element YouTube Music Apr 17 10:44:14 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:14 volumio volumio[893]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:14 volumio volumio[893]: Cannot find translation for source YouTube Music Apr 17 10:44:14 volumio volumio[893]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:14 volumio volumio[893]: info: [1744897454062] CoreMusicLibrary::Adding element LastFM Apr 17 10:44:14 volumio volumio[893]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:14 volumio volumio[893]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:14 volumio volumio[893]: Cannot find translation for source YouTube Music Apr 17 10:44:14 volumio volumio[893]: Cannot find translation for source LastFM Apr 17 10:44:14 volumio volumio[893]: info: [LastFM] scrobbler initiated! Apr 17 10:44:14 volumio volumio[893]: info: [LastFM] extended logging: false Apr 17 10:44:14 volumio volumio[893]: info: [LastFM] try scrobble stream/radio plays: true Apr 17 10:44:14 volumio volumio[893]: info: [LastFM] Left init routine Apr 17 10:44:14 volumio volumio[893]: info: [LastFM] Socket already connected: true Apr 17 10:44:14 volumio volumio[893]: info: Volumio Calling Home Apr 17 10:44:14 volumio sudo[1156]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 17 10:44:14 volumio sudo[1156]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:14 volumio sudo[1156]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:14 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:14 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:14 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:14 volumio volumio[893]: Unhandled rejection Error: No sockets available, cannot start. Apr 17 10:44:14 volumio volumio[893]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 17 10:44:14 volumio volumio[893]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 17 10:44:14 volumio volumio[893]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 17 10:44:14 volumio volumio[893]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 17 10:44:14 volumio volumio[893]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 17 10:44:14 volumio volumio[893]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 17 10:44:14 volumio volumio[893]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 17 10:44:14 volumio volumio[893]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 17 10:44:14 volumio volumio[893]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Apr 17 10:44:14 volumio volumio[893]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 17 10:44:14 volumio volumio[893]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 17 10:44:14 volumio volumio[893]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 17 10:44:14 volumio volumio[893]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 17 10:44:14 volumio volumio[893]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 17 10:44:14 volumio volumio[893]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 17 10:44:14 volumio volumio[893]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 17 10:44:14 volumio volumio[893]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Apr 17 10:44:14 volumio volumio[893]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:44:14 volumio volumio[893]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Apr 17 10:44:14 volumio volumio[893]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Apr 17 10:44:14 volumio volumio[893]: errno: -16, Apr 17 10:44:14 volumio volumio[893]: code: 'EBUSY', Apr 17 10:44:14 volumio volumio[893]: syscall: 'getaddrinfo', Apr 17 10:44:14 volumio volumio[893]: hostname: 'ws.audioscrobbler.com' Apr 17 10:44:14 volumio volumio[893]: } Apr 17 10:44:14 volumio volumio[893]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:44:14 volumio ntpd[659]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 17 10:44:15 volumio sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-17 10:43 Apr 17 10:44:15 volumio sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:15 volumio sudo[1183]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:44:16 volumio ntfs-3g[966]: Unmounting /dev/sda1 (FLAC_MUSIC) Apr 17 10:44:16 volumio sudo[1136]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:16 volumio sudo[1127]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:16 volumio systemd[1]: media-FLAC_MUSIC.mount: Succeeded. Apr 17 10:44:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 17 10:44:16 volumio systemd[1]: Started dynamicswap service. Apr 17 10:44:16 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 17 10:44:16 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 17 10:44:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Apr 17 10:44:16 volumio systemd[1]: Started dynamicswap service. Apr 17 10:44:16 volumio systemd[1]: Stopped Volumio Backend Module. Apr 17 10:44:16 volumio systemd[1]: Started Volumio Backend Module. Apr 17 10:44:16 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 17 10:44:17 volumio mpd[1167]: Apr 17 10:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 17 10:44:17 volumio ntpd[659]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 17 10:44:18 volumio ntpd[659]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 17 10:44:19 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:19 volumio systemd[1]: Started Music Player Daemon. Apr 17 10:44:19 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:19 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:19 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:19 volumio volumio[1199]: info: ----- Volumio3 ---- Apr 17 10:44:19 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:19 volumio volumio[1199]: info: ----- System startup ---- Apr 17 10:44:19 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:20 volumio ntpd[659]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 17 10:44:21 volumio volumio-remote-updater[487]: [2025-04-17 10:44:21] [connect] Successful connection Apr 17 10:44:21 volumio volumio[1199]: info: MYVOLUMIO Environment detected Apr 17 10:44:21 volumio volumio[1199]: info: Plugin folders cleanup Apr 17 10:44:21 volumio volumio[1199]: info: Scanning into folder /volumio/app/plugins/ Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category audio_interface Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category miscellanea Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category music_service Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category plugins.json Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category system_controller Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category user_interface Apr 17 10:44:21 volumio volumio[1199]: info: Scanning into folder /data/plugins/ Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category music_service Apr 17 10:44:21 volumio volumio[1199]: info: Scanning category user_interface Apr 17 10:44:21 volumio volumio[1199]: info: Plugin folders cleanup completed Apr 17 10:44:21 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:21 volumio volumio[1199]: info: ----- Core plugins startup ---- Apr 17 10:44:21 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:21 volumio volumio[1199]: info: Loading plugins from folder /volumio/app/plugins/ Apr 17 10:44:21 volumio volumio[1199]: info: Adding plugin upnp to MyMusic Plugins Apr 17 10:44:21 volumio volumio[1199]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 17 10:44:21 volumio volumio[1199]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 17 10:44:21 volumio volumio[1199]: info: Loading plugins from folder /data/plugins/ Apr 17 10:44:21 volumio volumio[1199]: info: Loading plugin "system"... Apr 17 10:44:21 volumio volumio[1199]: info: Loading plugin "appearance"... Apr 17 10:44:23 volumio volumio[1199]: info: Loading plugin "network"... Apr 17 10:44:23 volumio volumio[1199]: info: Refreshing Cached IP Addresses Apr 17 10:44:23 volumio sudo[1235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 17 10:44:23 volumio sudo[1235]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:23 volumio sudo[1235]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:23 volumio sudo[1237]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 17 10:44:23 volumio sudo[1237]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:23 volumio volumio[1199]: info: Loading plugin "services"... Apr 17 10:44:23 volumio volumio[1199]: info: Loading plugin "alsa_controller"... Apr 17 10:44:23 volumio sudo[1237]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:23 volumio sudo[1246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 17 10:44:23 volumio sudo[1246]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:23 volumio volumio[1199]: warn: Unable to locate the audio output device USB Audio DAC. Please configure a valid output device. Apr 17 10:44:23 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:44:23 volumio volumio[1199]: info: Loading plugin "wizard"... Apr 17 10:44:23 volumio volumio[1199]: info: Loading plugin "networkfs"... Apr 17 10:44:23 volumio volumio[1199]: info: Starting Udev Watcher for removable devices Apr 17 10:44:23 volumio volumio[1199]: info: Ignoring mount for partition: boot Apr 17 10:44:23 volumio volumio[1199]: info: Ignoring mount for partition: volumio Apr 17 10:44:23 volumio volumio[1199]: info: Ignoring mount for partition: volumio_data Apr 17 10:44:23 volumio volumio[1199]: info: Mounting Device FLAC_MUSIC Apr 17 10:44:24 volumio sudo[1263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/FLAC_MUSIC -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 17 10:44:24 volumio sudo[1263]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:24 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:24 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:24 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:25 volumio ntfs-3g[1272]: Version 2017.3.23AR.3 integrated FUSE 28 Apr 17 10:44:25 volumio ntfs-3g[1272]: Mounted /dev/sda1 (Read-Write, label "FLAC_MUSIC", NTFS 3.1) Apr 17 10:44:25 volumio ntfs-3g[1272]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 17 10:44:25 volumio ntfs-3g[1272]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Apr 17 10:44:25 volumio ntfs-3g[1272]: Global ownership and permissions enforced, configuration type 7 Apr 17 10:44:25 volumio sudo[1263]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:25 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:44:25 volumio volumio[1199]: info: Loading plugin "volumio_command_line_client"... Apr 17 10:44:25 volumio volumio[1199]: info: Loading plugin "upnp"... Apr 17 10:44:25 volumio volumio[1199]: info: [1744897465945] Starting Upmpd Daemon Apr 17 10:44:25 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:44:25 volumio volumio[1199]: info: Loading plugin "my_music"... Apr 17 10:44:25 volumio volumio[1199]: info: Loading plugin "mpd"... Apr 17 10:44:26 volumio volumio[1199]: info: Loading plugin "upnp_browser"... Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "alarm-clock"... Apr 17 10:44:27 volumio sudo[1246]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "airplay_emulation"... Apr 17 10:44:27 volumio volumio[1199]: info: Starting Shairport Sync Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "last_100"... Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "webradio"... Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "i2s_dacs"... Apr 17 10:44:27 volumio volumio[1199]: info: I2S DAC not set, start Auto-detection Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "volumiodiscovery"... Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 17 10:44:27 volumio node[1199]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** For more information see Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:44:27 volumio volumio[1199]: *** WARNING *** For more information see Apr 17 10:44:27 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:44:27 volumio node[1199]: *** WARNING *** For more information see Apr 17 10:44:27 volumio node[1199]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 17 10:44:27 volumio node[1199]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:44:27 volumio node[1199]: *** WARNING *** For more information see Apr 17 10:44:27 volumio volumio[1199]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 17 10:44:27 volumio volumio[1199]: info: Discovery: Started advertising with name: Volumio Apr 17 10:44:27 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:44:27 volumio volumio[1199]: info: Loading plugin "bandcamp"... Apr 17 10:44:29 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:29 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:29 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:29 volumio volumio[1199]: info: Loading plugin "spop"... Apr 17 10:44:31 volumio wpa_supplicant[796]: wlan0: SME: Trying to authenticate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2417 MHz) Apr 17 10:44:31 volumio kernel: wlan0: authenticate with f8:2d:c0:24:80:a5 Apr 17 10:44:31 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Apr 17 10:44:31 volumio volumio[1199]: info: Loading plugin "ytmusic"... Apr 17 10:44:32 volumio wpa_supplicant[796]: wlan0: Trying to associate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2417 MHz) Apr 17 10:44:32 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:44:32 volumio kernel: wlan0: authenticated Apr 17 10:44:32 volumio kernel: wlan0: associate with f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:44:32 volumio kernel: wlan0: RX AssocResp from f8:2d:c0:24:80:a5 (capab=0x431 status=0 aid=1) Apr 17 10:44:32 volumio kernel: wlan0: associated Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: connected to Access Point `2G Grejo ' Apr 17 10:44:32 volumio wpa_supplicant[796]: wlan0: Associated with f8:2d:c0:24:80:a5 Apr 17 10:44:32 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 17 10:44:32 volumio dhcpcd[811]: DUID 00:01:00:01:2e:f2:a3:b0:b8:27:eb:3b:13:d9 Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: adding address fe80::ab75:a9bd:9b49:be53 Apr 17 10:44:32 volumio dhcpcd[811]: ipv6_addaddr1: Permission denied Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: carrier lost Apr 17 10:44:32 volumio systemd-udevd[1281]: Process '/sbin/crda' failed with exit code 255. Apr 17 10:44:32 volumio kernel: cryptd: max_cpu_qlen set to 1000 Apr 17 10:44:32 volumio wpa_supplicant[796]: wlan0: WPA: Key negotiation completed with f8:2d:c0:24:80:a5 [PTK=CCMP GTK=CCMP] Apr 17 10:44:32 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-CONNECTED - Connection to f8:2d:c0:24:80:a5 completed [id=0 id_str=] Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:44:32 volumio dhcpcd[811]: wlan0: rebinding lease of 192.168.0.5 Apr 17 10:44:33 volumio dhcpcd[811]: wlan0: soliciting an IPv6 router Apr 17 10:44:34 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:34 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:34 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:35 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 17 10:44:36 volumio volumio-remote-updater[487]: [2025-04-17 10:44:36] [connect] Successful connection Apr 17 10:44:37 volumio volumio[1199]: info: Loading plugin "outputs"... Apr 17 10:44:37 volumio volumio[1199]: info: Loading plugin "albumart"... Apr 17 10:44:37 volumio volumio[1199]: info: Plugin example_plugin is not enabled Apr 17 10:44:37 volumio volumio[1199]: info: Loading plugin "inputs"... Apr 17 10:44:37 volumio volumio[1199]: info: Loading plugin "updater_comm"... Apr 17 10:44:37 volumio dhcpcd[811]: wlan0: probing for an IPv4LL address Apr 17 10:44:37 volumio dhcpcd[811]: wlan0: DHCP lease expired Apr 17 10:44:37 volumio dhcpcd[811]: wlan0: soliciting a DHCP lease Apr 17 10:44:38 volumio volumio[1199]: info: Plugin mpdemulation is not enabled Apr 17 10:44:38 volumio volumio[1199]: info: Loading plugin "rest_api"... Apr 17 10:44:38 volumio volumio[1199]: info: Loading plugin "websocket"... Apr 17 10:44:38 volumio volumio[1199]: info: Starting Socket.io Server version 2.3.0 Apr 17 10:44:38 volumio volumio[1199]: info: Loading plugin "lastfm"... Apr 17 10:44:38 volumio volumio[1199]: Forking 3 albumart workers Apr 17 10:44:39 volumio volumio[1199]: info: Loading i18n strings for locale pt Apr 17 10:44:39 volumio volumio[1199]: Updating browse sources language Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:39 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::initPlayerControls Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:39 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:39 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:39 volumio volumio[1199]: Express server listening on port 3000 Apr 17 10:44:39 volumio volumio[1199]: [Metrics] WebUI: 20s 978.33ms Apr 17 10:44:39 volumio systemd[1]: nmbd.service: Start operation timed out. Terminating. Apr 17 10:44:39 volumio systemd[1]: nmbd.service: Main process exited, code=killed, status=15/TERM Apr 17 10:44:39 volumio systemd[1]: nmbd.service: Failed with result 'timeout'. Apr 17 10:44:39 volumio systemd[1]: Failed to start Samba NMB Daemon. Apr 17 10:44:39 volumio volumio[1199]: info: CoreStateMachine::resetVolumioState Apr 17 10:44:39 volumio volumio[1199]: info: CoreStateMachine::getcurrentVolume Apr 17 10:44:39 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:44:39 volumio systemd[1]: Starting Samba Winbind Daemon... Apr 17 10:44:40 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:40 volumio sudo[1380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 17 10:44:40 volumio sudo[1380]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:40 volumio sudo[1380]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:40 volumio sudo[1382]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 17 10:44:40 volumio sudo[1382]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:40 volumio sudo[1382]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:40 volumio volumio[1199]: info: Volumio Network Manager: Network status updated: 0 Apr 17 10:44:40 volumio volumio[1199]: info: CoreStateMachine::pushState Apr 17 10:44:40 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:40 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:44:40 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:40 volumio volumio[1199]: info: CoreStateMachine::updateTrackBlock Apr 17 10:44:40 volumio volumio[1199]: info: CorePlayQueue::getTrackBlock Apr 17 10:44:40 volumio volumio[1199]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:44:40 volumio winbindd[1372]: [2025/04/17 10:44:40.628411, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Apr 17 10:44:40 volumio winbindd[1372]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Apr 17 10:44:40 volumio winbindd[1372]: [2025/04/17 10:44:40.815007, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 17 10:44:40 volumio winbindd[1372]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Apr 17 10:44:40 volumio systemd[1]: Started Samba Winbind Daemon. Apr 17 10:44:40 volumio volumio[1199]: Starting albumart workers Apr 17 10:44:40 volumio systemd[1]: Starting Samba SMB Daemon... Apr 17 10:44:41 volumio volumio-remote-updater[487]: [2025-04-17 10:44:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744897476 101 Apr 17 10:44:41 volumio volumio[1199]: 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: 1 Apr 17 10:44:41 volumio volumio[1199]: info: CoreStateMachine::pushState Apr 17 10:44:41 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:41 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:41 volumio volumio[1199]: Starting albumart workers Apr 17 10:44:41 volumio volumio[1199]: Starting albumart workers Apr 17 10:44:41 volumio volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 17 10:44:41 volumio volumio[1199]: info: Reloading queue from file Apr 17 10:44:41 volumio volumio[1199]: info: Setting Device type: Raspberry PI Apr 17 10:44:41 volumio volumio[1199]: info: CoreStateMachine::setRepeat null single undefined Apr 17 10:44:41 volumio volumio[1199]: info: CoreStateMachine::pushState Apr 17 10:44:41 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:41 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:44:41 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:41 volumio volumio[1199]: info: CoreStateMachine::setRandom null Apr 17 10:44:41 volumio volumio[1199]: info: CoreStateMachine::pushState Apr 17 10:44:41 volumio volumio[1199]: info: CorePlayQueue::getTrack 0 Apr 17 10:44:41 volumio volumio[1199]: info: CoreCommandRouter::volumioPushState Apr 17 10:44:41 volumio sudo[1401]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 17 10:44:41 volumio sudo[1401]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:41 volumio sudo[1401]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:41 volumio volumio[1199]: info: Upmpdcli Daemon Started Apr 17 10:44:42 volumio volumio[1199]: info: Completed loading Core Plugins Apr 17 10:44:42 volumio volumio[1199]: info: Preparing to generate the ALSA configuration file Apr 17 10:44:42 volumio volumio[1199]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 17 10:44:42 volumio dhcpcd[811]: wlan0: using IPv4LL address 169.254.166.235 Apr 17 10:44:42 volumio dhcpcd[811]: wlan0: adding route to 169.254.0.0/16 Apr 17 10:44:42 volumio volumio[1199]: info: Reading ALSA contributions from plugins. Apr 17 10:44:42 volumio dhcpcd[811]: wlan0: adding default route Apr 17 10:44:42 volumio avahi-daemon[492]: Joining mDNS multicast group on interface wlan0.IPv4 with address 169.254.166.235. Apr 17 10:44:42 volumio avahi-daemon[492]: New relevant interface wlan0.IPv4 for mDNS. Apr 17 10:44:42 volumio avahi-daemon[492]: Registering new address record for 169.254.166.235 on wlan0.IPv4. Apr 17 10:44:42 volumio volumio[1199]: info: Asound.conf file unchanged, so no further update is needed Apr 17 10:44:42 volumio volumio[1199]: info: Output device has changed, restarting MPD Apr 17 10:44:42 volumio volumio[1199]: info: Output device has changed, restarting Shairport Sync Apr 17 10:44:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:42 volumio sudo[1420]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:44:42 volumio sudo[1420]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:42 volumio sudo[1420]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:42 volumio sudo[1422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:44:42 volumio sudo[1422]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:42 volumio systemd[1]: Stopping Music Player Daemon... Apr 17 10:44:42 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:42 volumio volumio[1199]: info: ___________ START PLUGINS ___________ Apr 17 10:44:42 volumio volumio[1199]: info: ControllerMpd::onStart: Initializing MPD Apr 17 10:44:42 volumio volumio[1199]: info: Creating MPD Configuration file Apr 17 10:44:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:44:42 volumio systemd[1]: mpd.service: Succeeded. Apr 17 10:44:42 volumio systemd[1]: Stopped Music Player Daemon. Apr 17 10:44:42 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:42 volumio volumio[1199]: info: [1744897482876] CoreMusicLibrary::Adding element Servidores multimédia Apr 17 10:44:42 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:42 volumio sudo[1437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:44:42 volumio sudo[1437]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:42 volumio systemd[1]: Starting Music Player Daemon... Apr 17 10:44:42 volumio sudo[1437]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:43 volumio sudo[1443]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:44:43 volumio sudo[1443]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:43 volumio smbd[1395]: [2025/04/17 10:44:43.147764, 0] ../lib/util/become_daemon.c:138(daemon_ready) Apr 17 10:44:43 volumio smbd[1395]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Apr 17 10:44:43 volumio systemd[1]: Started Samba SMB Daemon. Apr 17 10:44:43 volumio sudo[1444]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 17 10:44:43 volumio sudo[1444]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:43 volumio sudo[1444]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:43 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Apr 17 10:44:43 volumio systemd[1]: mpd.service: Succeeded. Apr 17 10:44:43 volumio systemd[1]: Stopped Music Player Daemon. Apr 17 10:44:43 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:43 volumio systemd[1]: Starting Music Player Daemon... Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:43 volumio volumio[1199]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:43 volumio volumio[1199]: info: [1744897483471] CoreMusicLibrary::Adding element Last_100 Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:43 volumio volumio[1199]: info: [1744897483480] CoreMusicLibrary::Adding element Webradio Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:44:43 volumio volumio[1199]: info: Initializing BBC Radios Apr 17 10:44:43 volumio sudo[1457]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 17 10:44:43 volumio sudo[1457]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:43 volumio sudo[1457]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:43 volumio ntpd[659]: Listen normally on 3 wlan0 169.254.166.235:123 Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:43 volumio volumio[1199]: info: [1744897483677] CoreMusicLibrary::Adding element Bandcamp Discover Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:43 volumio volumio[1199]: info: Creating Spotify config file Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:43 volumio ntpd[659]: new interface(s) found: waking up resolver Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:43 volumio volumio[1199]: info: [1744897483906] CoreMusicLibrary::Adding element YouTube Music Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source YouTube Music Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:44:43 volumio volumio[1199]: info: [1744897483933] CoreMusicLibrary::Adding element LastFM Apr 17 10:44:43 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source Bandcamp Discover Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source YouTube Music Apr 17 10:44:43 volumio volumio[1199]: Cannot find translation for source LastFM Apr 17 10:44:43 volumio volumio[1199]: info: [LastFM] scrobbler initiated! Apr 17 10:44:43 volumio volumio[1199]: info: [LastFM] extended logging: false Apr 17 10:44:43 volumio volumio[1199]: info: [LastFM] try scrobble stream/radio plays: true Apr 17 10:44:43 volumio volumio[1199]: info: [LastFM] Left init routine Apr 17 10:44:43 volumio volumio[1199]: info: [LastFM] Socket already connected: true Apr 17 10:44:43 volumio volumio[1199]: info: Volumio Calling Home Apr 17 10:44:44 volumio volumio[1199]: info: Volumio Network Manager: Network status updated: 2 Apr 17 10:44:44 volumio volumio[1199]: info: MPD Permissions set Apr 17 10:44:44 volumio volumio[1199]: info: MPD Permissions set Apr 17 10:44:44 volumio volumio[1199]: info: Spotify config file written Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio sudo[1499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 17 10:44:44 volumio sudo[1499]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:44:44 volumio volumio[1199]: info: No need to fix Spotify hosts Apr 17 10:44:44 volumio volumio[1199]: info: Starting Shairport Sync Apr 17 10:44:44 volumio volumio[1199]: info: Starting Shairport Sync Apr 17 10:44:44 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:44:44 volumio go-librespot[1509]: go-librespot daemon starting... Apr 17 10:44:44 volumio volumio[1199]: info: Starting Shairport Sync Apr 17 10:44:44 volumio sudo[1499]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:44 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:44 volumio sudo[1511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 17 10:44:44 volumio sudo[1511]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:44 volumio sudo[1514]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 17 10:44:44 volumio sudo[1514]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:44 volumio sudo[1521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 17 10:44:44 volumio sudo[1521]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:44 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 17 10:44:44 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 17 10:44:44 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 17 10:44:44 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 17 10:44:45 volumio sudo[1511]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:45 volumio sudo[1514]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:45 volumio sudo[1521]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:45 volumio volumio[1199]: info: Shairport-Sync Started Apr 17 10:44:45 volumio volumio[1199]: Error adding Membership: Error: addMembership EINVAL Apr 17 10:44:45 volumio volumio[1199]: info: Shairport-Sync Started Apr 17 10:44:45 volumio volumio[1199]: info: Shairport-Sync Started Apr 17 10:44:45 volumio volumio[1113]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 17 10:44:45 volumio go-librespot[1509]: time="2025-04-17T10:44:45-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:44:45 volumio go-librespot[1509]: time="2025-04-17T10:44:45-03:00" level=debug msg="app state loaded" Apr 17 10:44:45 volumio go-librespot[1509]: time="2025-04-17T10:44:45-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:44:46 volumio mpd[1472]: Apr 17 10:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 17 10:44:47 volumio volumio[1199]: info: go-librespot daemon successfully initialized Apr 17 10:44:48 volumio systemd[1]: Started Music Player Daemon. Apr 17 10:44:48 volumio sudo[1443]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:48 volumio sudo[1422]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:48 volumio volumio[1199]: info: Completed starting Core Plugins Apr 17 10:44:48 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:48 volumio volumio[1199]: info: ----- MyVolumio plugins startup ---- Apr 17 10:44:48 volumio volumio[1199]: info: ------------------------------------------- Apr 17 10:44:48 volumio volumio[1199]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 17 10:44:48 volumio volumio[1199]: error: MPD error: The expression evaluated to a falsy value: Apr 17 10:44:48 volumio volumio[1199]: assert.ok(self.idling) Apr 17 10:44:48 volumio volumio[1199]: error: The expression evaluated to a falsy value: Apr 17 10:44:48 volumio volumio[1199]: assert.ok(self.idling) Apr 17 10:44:48 volumio volumio[1199]: info: MPD running with PID1472 Apr 17 10:44:48 volumio volumio[1199]: ,establishing connection Apr 17 10:44:48 volumio volumio[1199]: error: updateQueue error: null Apr 17 10:44:48 volumio volumio[1199]: error: updateQueue error: null Apr 17 10:44:50 volumio volumio[1199]: info: Initializing connection to go-librespot Websocket Apr 17 10:44:51 volumio dhcpcd[811]: wlan0: carrier lost Apr 17 10:44:51 volumio kernel: wlan0: disassociated from f8:2d:c0:24:80:a5 (Reason: 4=DISASSOC_DUE_TO_INACTIVITY) Apr 17 10:44:51 volumio avahi-daemon[492]: Withdrawing address record for 169.254.166.235 on wlan0. Apr 17 10:44:51 volumio avahi-daemon[492]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 169.254.166.235. Apr 17 10:44:51 volumio avahi-daemon[492]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 17 10:44:51 volumio dhcpcd[811]: wlan0: deleting route to 169.254.0.0/16 Apr 17 10:44:51 volumio dhcpcd[811]: wlan0: deleting default route Apr 17 10:44:51 volumio kernel: wlan0: authenticate with f8:2d:c0:24:80:a5 Apr 17 10:44:51 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Apr 17 10:44:51 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:2d:c0:24:80:a5 reason=4 Apr 17 10:44:51 volumio volumio[1199]: info: Discovery: A device disappeared from network Apr 17 10:44:51 volumio volumio[1199]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Apr 17 10:44:51 volumio wpa_supplicant[796]: wlan0: SME: Trying to authenticate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2417 MHz) Apr 17 10:44:52 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 17 10:44:52 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:44:52 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 2/3) Apr 17 10:44:52 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 3/3) Apr 17 10:44:52 volumio kernel: wlan0: authentication with f8:2d:c0:24:80:a5 timed out Apr 17 10:44:53 volumio ntpd[659]: Deleting interface #3 wlan0, 169.254.166.235#123, interface stats: received=0, sent=0, dropped=0, active_time=10 secs Apr 17 10:44:53 volumio volumio[1199]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo ENOTFOUND oauth-performer.prod.vlmapi.io Apr 17 10:44:53 volumio volumio[1199]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 17 10:44:54 volumio volumio[1199]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:44:54 volumio volumio[1199]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Apr 17 10:44:54 volumio volumio[1199]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Apr 17 10:44:54 volumio volumio[1199]: errno: -3007, Apr 17 10:44:54 volumio volumio[1199]: code: 'ENOTFOUND', Apr 17 10:44:54 volumio volumio[1199]: syscall: 'getaddrinfo', Apr 17 10:44:54 volumio volumio[1199]: hostname: 'ws.audioscrobbler.com' Apr 17 10:44:54 volumio volumio[1199]: } Apr 17 10:44:54 volumio volumio[1199]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:44:54 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:54 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:44:55 volumio sudo[1593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-17 10:43 Apr 17 10:44:55 volumio sudo[1593]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:44:55 volumio go-librespot[1509]: time="2025-04-17T10:44:55-03: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" Apr 17 10:44:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:44:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:44:55 volumio sudo[1593]: pam_unix(sudo:session): session closed for user root Apr 17 10:44:58 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:44:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Apr 17 10:44:58 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:44:58 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:44:58 volumio go-librespot[1600]: go-librespot daemon starting... Apr 17 10:44:58 volumio go-librespot[1600]: time="2025-04-17T10:44:58-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:44:58 volumio go-librespot[1600]: time="2025-04-17T10:44:58-03:00" level=debug msg="app state loaded" Apr 17 10:44:58 volumio go-librespot[1600]: time="2025-04-17T10:44:58-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:44:58 volumio go-librespot[1600]: time="2025-04-17T10:44:58-03: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" Apr 17 10:44:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:44:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:44:58 volumio volumio-remote-updater[487]: [2025-04-17 10:44:58] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 17 10:44:58 volumio volumio-remote-updater[487]: [2025-04-17 10:44:58] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 17 10:44:58 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:44:58 volumio ntfs-3g[1272]: Unmounting /dev/sda1 (FLAC_MUSIC) Apr 17 10:44:58 volumio systemd[1]: media-FLAC_MUSIC.mount: Succeeded. Apr 17 10:44:58 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Apr 17 10:44:59 volumio systemd[1]: Started dynamicswap service. Apr 17 10:44:59 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Apr 17 10:44:59 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Apr 17 10:44:59 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 17 10:44:59 volumio systemd[1]: Stopped Volumio Backend Module. Apr 17 10:44:59 volumio systemd[1]: Started Volumio Backend Module. Apr 17 10:44:59 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:44:59 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:44:59 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:01 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Apr 17 10:45:01 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:01 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:01 volumio go-librespot[1630]: go-librespot daemon starting... Apr 17 10:45:01 volumio go-librespot[1630]: time="2025-04-17T10:45:01-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:01 volumio go-librespot[1630]: time="2025-04-17T10:45:01-03:00" level=debug msg="app state loaded" Apr 17 10:45:01 volumio go-librespot[1630]: time="2025-04-17T10:45:01-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:01 volumio go-librespot[1630]: time="2025-04-17T10:45:01-03: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" Apr 17 10:45:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:03 volumio volumio[1615]: info: ------------------------------------------- Apr 17 10:45:03 volumio volumio[1615]: info: ----- Volumio3 ---- Apr 17 10:45:03 volumio volumio[1615]: info: ------------------------------------------- Apr 17 10:45:03 volumio volumio[1615]: info: ----- System startup ---- Apr 17 10:45:03 volumio volumio[1615]: info: ------------------------------------------- Apr 17 10:45:03 volumio volumio-remote-updater[487]: [2025-04-17 10:45:03] [connect] Successful connection Apr 17 10:45:04 volumio volumio[1615]: info: MYVOLUMIO Environment detected Apr 17 10:45:04 volumio volumio[1615]: info: Plugin folders cleanup Apr 17 10:45:04 volumio volumio[1615]: info: Scanning into folder /volumio/app/plugins/ Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category audio_interface Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category miscellanea Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category music_service Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category plugins.json Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category system_controller Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category user_interface Apr 17 10:45:04 volumio volumio[1615]: info: Scanning into folder /data/plugins/ Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category music_service Apr 17 10:45:04 volumio volumio[1615]: info: Scanning category user_interface Apr 17 10:45:04 volumio volumio[1615]: info: Plugin folders cleanup completed Apr 17 10:45:04 volumio volumio[1615]: info: ------------------------------------------- Apr 17 10:45:04 volumio volumio[1615]: info: ----- Core plugins startup ---- Apr 17 10:45:04 volumio volumio[1615]: info: ------------------------------------------- Apr 17 10:45:04 volumio volumio[1615]: info: Loading plugins from folder /volumio/app/plugins/ Apr 17 10:45:04 volumio volumio[1615]: info: Adding plugin upnp to MyMusic Plugins Apr 17 10:45:04 volumio volumio[1615]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 17 10:45:04 volumio volumio[1615]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 17 10:45:04 volumio volumio[1615]: info: Loading plugins from folder /data/plugins/ Apr 17 10:45:04 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:04 volumio volumio[1615]: info: Loading plugin "system"... Apr 17 10:45:04 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:04 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:04 volumio volumio[1615]: info: Loading plugin "appearance"... Apr 17 10:45:05 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Apr 17 10:45:05 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:05 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:05 volumio go-librespot[1655]: go-librespot daemon starting... Apr 17 10:45:05 volumio go-librespot[1655]: time="2025-04-17T10:45:05-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:05 volumio go-librespot[1655]: time="2025-04-17T10:45:05-03:00" level=debug msg="app state loaded" Apr 17 10:45:05 volumio go-librespot[1655]: time="2025-04-17T10:45:05-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:05 volumio go-librespot[1655]: time="2025-04-17T10:45:05-03: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" Apr 17 10:45:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:05 volumio wpa_supplicant[796]: wlan0: SME: Trying to authenticate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2442 MHz) Apr 17 10:45:05 volumio kernel: wlan0: authenticate with f8:2d:c0:24:80:a5 Apr 17 10:45:05 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Apr 17 10:45:06 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:45:06 volumio kernel: wlan0: authenticated Apr 17 10:45:06 volumio wpa_supplicant[796]: wlan0: Trying to associate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2442 MHz) Apr 17 10:45:06 volumio kernel: wlan0: associate with f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:45:06 volumio kernel: wlan0: RX AssocResp from f8:2d:c0:24:80:a5 (capab=0x431 status=0 aid=2) Apr 17 10:45:06 volumio kernel: wlan0: associated Apr 17 10:45:06 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:45:06 volumio wpa_supplicant[796]: wlan0: Associated with f8:2d:c0:24:80:a5 Apr 17 10:45:06 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 17 10:45:06 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:45:06 volumio dhcpcd[811]: wlan0: carrier lost Apr 17 10:45:06 volumio systemd-udevd[1662]: Process '/sbin/crda' failed with exit code 255. Apr 17 10:45:06 volumio wpa_supplicant[796]: wlan0: WPA: Key negotiation completed with f8:2d:c0:24:80:a5 [PTK=CCMP GTK=CCMP] Apr 17 10:45:06 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-CONNECTED - Connection to f8:2d:c0:24:80:a5 completed [id=0 id_str=] Apr 17 10:45:06 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:45:06 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:45:07 volumio dhcpcd[811]: wlan0: soliciting an IPv6 router Apr 17 10:45:07 volumio volumio[1615]: info: Loading plugin "network"... Apr 17 10:45:07 volumio volumio[1615]: info: Refreshing Cached IP Addresses Apr 17 10:45:07 volumio sudo[1677]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 17 10:45:07 volumio sudo[1677]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:07 volumio sudo[1677]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:07 volumio sudo[1679]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 17 10:45:07 volumio sudo[1679]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:07 volumio sudo[1679]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:07 volumio dhcpcd[811]: wlan0: soliciting a DHCP lease Apr 17 10:45:07 volumio volumio[1615]: info: Loading plugin "services"... Apr 17 10:45:07 volumio volumio[1615]: info: Loading plugin "alsa_controller"... Apr 17 10:45:07 volumio sudo[1688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 17 10:45:07 volumio sudo[1688]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:07 volumio volumio[1615]: warn: Unable to locate the audio output device USB Audio DAC. Please configure a valid output device. Apr 17 10:45:07 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:45:07 volumio volumio[1615]: info: Loading plugin "wizard"... Apr 17 10:45:07 volumio volumio[1615]: info: Loading plugin "networkfs"... Apr 17 10:45:07 volumio volumio[1615]: info: Starting Udev Watcher for removable devices Apr 17 10:45:07 volumio volumio[1615]: info: Ignoring mount for partition: boot Apr 17 10:45:07 volumio volumio[1615]: info: Ignoring mount for partition: volumio Apr 17 10:45:07 volumio volumio[1615]: info: Ignoring mount for partition: volumio_data Apr 17 10:45:07 volumio volumio[1615]: info: Mounting Device FLAC_MUSIC Apr 17 10:45:08 volumio sudo[1744]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/FLAC_MUSIC -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 17 10:45:08 volumio sudo[1744]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Apr 17 10:45:08 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:08 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:08 volumio go-librespot[1747]: go-librespot daemon starting... Apr 17 10:45:08 volumio go-librespot[1747]: time="2025-04-17T10:45:08-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:08 volumio go-librespot[1747]: time="2025-04-17T10:45:08-03:00" level=debug msg="app state loaded" Apr 17 10:45:08 volumio go-librespot[1747]: time="2025-04-17T10:45:08-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:08 volumio go-librespot[1747]: time="2025-04-17T10:45:08-03: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" Apr 17 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:09 volumio ntfs-3g[1755]: Version 2017.3.23AR.3 integrated FUSE 28 Apr 17 10:45:09 volumio ntfs-3g[1755]: Mounted /dev/sda1 (Read-Write, label "FLAC_MUSIC", NTFS 3.1) Apr 17 10:45:09 volumio ntfs-3g[1755]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8 Apr 17 10:45:09 volumio ntfs-3g[1755]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sda1,blkdev,blksize=4096 Apr 17 10:45:09 volumio ntfs-3g[1755]: Global ownership and permissions enforced, configuration type 7 Apr 17 10:45:09 volumio sudo[1744]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:09 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:45:09 volumio volumio[1615]: info: Loading plugin "volumio_command_line_client"... Apr 17 10:45:09 volumio volumio[1615]: info: Loading plugin "upnp"... Apr 17 10:45:09 volumio volumio[1615]: info: [1744897509620] Starting Upmpd Daemon Apr 17 10:45:09 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:45:09 volumio volumio[1615]: info: Loading plugin "my_music"... Apr 17 10:45:09 volumio volumio[1615]: info: Loading plugin "mpd"... Apr 17 10:45:09 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:09 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:09 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:10 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 17 10:45:10 volumio dhcpcd[811]: wlan0: offered 192.168.0.3 from 192.168.0.1 Apr 17 10:45:10 volumio volumio[1615]: info: Loading plugin "upnp_browser"... Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "alarm-clock"... Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "airplay_emulation"... Apr 17 10:45:11 volumio volumio[1615]: info: Starting Shairport Sync Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "last_100"... Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "webradio"... Apr 17 10:45:11 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Apr 17 10:45:11 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:11 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:11 volumio go-librespot[1761]: go-librespot daemon starting... Apr 17 10:45:11 volumio go-librespot[1761]: time="2025-04-17T10:45:11-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:11 volumio go-librespot[1761]: time="2025-04-17T10:45:11-03:00" level=debug msg="app state loaded" Apr 17 10:45:11 volumio go-librespot[1761]: time="2025-04-17T10:45:11-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:11 volumio go-librespot[1761]: time="2025-04-17T10:45:11-03: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" Apr 17 10:45:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "i2s_dacs"... Apr 17 10:45:11 volumio volumio[1615]: info: I2S DAC not set, start Auto-detection Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "volumiodiscovery"... Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** For more information see Apr 17 10:45:11 volumio node[1615]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:45:11 volumio volumio[1615]: *** WARNING *** For more information see Apr 17 10:45:11 volumio node[1615]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:45:11 volumio node[1615]: *** WARNING *** For more information see Apr 17 10:45:11 volumio node[1615]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 17 10:45:11 volumio node[1615]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 17 10:45:11 volumio node[1615]: *** WARNING *** For more information see Apr 17 10:45:11 volumio volumio[1615]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 17 10:45:11 volumio volumio[1615]: info: Discovery: Started advertising with name: Volumio Apr 17 10:45:11 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 10:45:11 volumio volumio[1615]: info: Loading plugin "bandcamp"... Apr 17 10:45:12 volumio dhcpcd[811]: wlan0: probing address 192.168.0.3/24 Apr 17 10:45:14 volumio volumio[1615]: info: Loading plugin "spop"... Apr 17 10:45:14 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Apr 17 10:45:14 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:14 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:14 volumio go-librespot[1771]: go-librespot daemon starting... Apr 17 10:45:14 volumio go-librespot[1771]: time="2025-04-17T10:45:14-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:14 volumio go-librespot[1771]: time="2025-04-17T10:45:14-03:00" level=debug msg="app state loaded" Apr 17 10:45:14 volumio go-librespot[1771]: time="2025-04-17T10:45:14-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:14 volumio go-librespot[1771]: time="2025-04-17T10:45:14-03: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" Apr 17 10:45:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:15 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:15 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:15 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:16 volumio volumio[1113]: ..................................................................................................................................++++ Apr 17 10:45:16 volumio volumio-remote-updater[487]: [2025-04-17 10:45:16] [connect] Successful connection Apr 17 10:45:16 volumio volumio[1615]: info: Loading plugin "ytmusic"... Apr 17 10:45:17 volumio dhcpcd[811]: wlan0: leased 192.168.0.3 for 20 seconds Apr 17 10:45:17 volumio dhcpcd[811]: wlan0: adding route to 192.168.0.0/24 Apr 17 10:45:17 volumio dhcpcd[811]: wlan0: adding default route via 192.168.0.1 Apr 17 10:45:17 volumio avahi-daemon[492]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.3. Apr 17 10:45:17 volumio avahi-daemon[492]: New relevant interface wlan0.IPv4 for mDNS. Apr 17 10:45:17 volumio avahi-daemon[492]: Registering new address record for 192.168.0.3 on wlan0.IPv4. Apr 17 10:45:18 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Apr 17 10:45:18 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:18 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:18 volumio go-librespot[1818]: go-librespot daemon starting... Apr 17 10:45:18 volumio go-librespot[1818]: time="2025-04-17T10:45:18-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:18 volumio go-librespot[1818]: time="2025-04-17T10:45:18-03:00" level=debug msg="app state loaded" Apr 17 10:45:18 volumio go-librespot[1818]: time="2025-04-17T10:45:18-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:18 volumio dhcpcd[811]: wlan0: carrier lost Apr 17 10:45:18 volumio kernel: wlan0: deauthenticated from f8:2d:c0:24:80:a5 (Reason: 6=CLASS2_FRAME_FROM_NONAUTH_STA) Apr 17 10:45:18 volumio avahi-daemon[492]: Withdrawing address record for 192.168.0.3 on wlan0. Apr 17 10:45:18 volumio avahi-daemon[492]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.0.3. Apr 17 10:45:18 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-DISCONNECTED bssid=f8:2d:c0:24:80:a5 reason=6 Apr 17 10:45:18 volumio dhcpcd[811]: wlan0: deleting route to 192.168.0.0/24 Apr 17 10:45:18 volumio dhcpcd[811]: wlan0: deleting default route via 192.168.0.1 Apr 17 10:45:18 volumio avahi-daemon[492]: Interface wlan0.IPv4 no longer relevant for mDNS. Apr 17 10:45:18 volumio wpa_supplicant[796]: wlan0: SME: Trying to authenticate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2442 MHz) Apr 17 10:45:18 volumio kernel: wlan0: authenticate with f8:2d:c0:24:80:a5 Apr 17 10:45:18 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Apr 17 10:45:18 volumio sudo[1688]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:19 volumio volumio[1113]: .............++++ Apr 17 10:45:19 volumio volumio[1113]: e is 65537 (0x010001) Apr 17 10:45:19 volumio volumio[1113]: writing RSA key Apr 17 10:45:19 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 17 10:45:19 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:45:19 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 2/3) Apr 17 10:45:19 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 3/3) Apr 17 10:45:19 volumio kernel: wlan0: authentication with f8:2d:c0:24:80:a5 timed out Apr 17 10:45:20 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:20 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:20 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:20 volumio ntpd[659]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Apr 17 10:45:21 volumio ntpd[659]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "outputs"... Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "albumart"... Apr 17 10:45:23 volumio volumio[1615]: info: Plugin example_plugin is not enabled Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "inputs"... Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "updater_comm"... Apr 17 10:45:23 volumio go-librespot[1818]: time="2025-04-17T10:45:23-03: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" Apr 17 10:45:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:23 volumio volumio[1615]: info: Plugin mpdemulation is not enabled Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "rest_api"... Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "websocket"... Apr 17 10:45:23 volumio volumio[1615]: info: Starting Socket.io Server version 2.3.0 Apr 17 10:45:23 volumio volumio[1615]: info: Loading plugin "lastfm"... Apr 17 10:45:24 volumio volumio[1615]: Forking 3 albumart workers Apr 17 10:45:24 volumio kernel: wlan0: authenticate with f8:2d:c0:24:80:a5 Apr 17 10:45:24 volumio kernel: wlan0: 80 MHz not supported, disabling VHT Apr 17 10:45:24 volumio wpa_supplicant[796]: wlan0: SME: Trying to authenticate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2452 MHz) Apr 17 10:45:24 volumio ntpd[659]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Apr 17 10:45:24 volumio volumio[1615]: info: Loading i18n strings for locale pt Apr 17 10:45:24 volumio volumio[1615]: Updating browse sources language Apr 17 10:45:24 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:25 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:25 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:25 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::initPlayerControls Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:25 volumio kernel: wlan0: send auth to f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:45:25 volumio wpa_supplicant[796]: wlan0: Trying to associate with f8:2d:c0:24:80:a5 (SSID='2G Grejo ' freq=2452 MHz) Apr 17 10:45:25 volumio kernel: wlan0: authenticated Apr 17 10:45:25 volumio kernel: wlan0: associate with f8:2d:c0:24:80:a5 (try 1/3) Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:45:25 volumio kernel: wlan0: RX AssocResp from f8:2d:c0:24:80:a5 (capab=0x431 status=0 aid=2) Apr 17 10:45:25 volumio volumio[1615]: Express server listening on port 3000 Apr 17 10:45:25 volumio volumio[1615]: [Metrics] WebUI: 23s 680.80ms Apr 17 10:45:25 volumio wpa_supplicant[796]: wlan0: Associated with f8:2d:c0:24:80:a5 Apr 17 10:45:25 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Apr 17 10:45:25 volumio kernel: wlan0: associated Apr 17 10:45:25 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:45:25 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:45:25 volumio dhcpcd[811]: wlan0: carrier lost Apr 17 10:45:25 volumio systemd-udevd[1899]: Process '/sbin/crda' failed with exit code 255. Apr 17 10:45:25 volumio volumio[1615]: info: CoreStateMachine::resetVolumioState Apr 17 10:45:25 volumio volumio[1615]: info: CoreStateMachine::getcurrentVolume Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:45:25 volumio wpa_supplicant[796]: wlan0: WPA: Key negotiation completed with f8:2d:c0:24:80:a5 [PTK=CCMP GTK=CCMP] Apr 17 10:45:25 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-CONNECTED - Connection to f8:2d:c0:24:80:a5 completed [id=0 id_str=] Apr 17 10:45:25 volumio dhcpcd[811]: wlan0: carrier acquired Apr 17 10:45:25 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:45:25 volumio dhcpcd[811]: wlan0: IAID 00:18:8a:a6 Apr 17 10:45:25 volumio sudo[1923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 17 10:45:25 volumio sudo[1923]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:25 volumio sudo[1923]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:25 volumio sudo[1926]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 17 10:45:25 volumio sudo[1926]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:25 volumio sudo[1926]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:25 volumio volumio[1615]: info: Volumio Network Manager: Network status updated: 0 Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::pushState Apr 17 10:45:26 volumio volumio[1615]: info: CorePlayQueue::getTrack 0 Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::volumioPushState Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::updateTrackBlock Apr 17 10:45:26 volumio volumio[1615]: info: CorePlayQueue::getTrackBlock Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::volumioRetrievevolume Apr 17 10:45:26 volumio dhcpcd[811]: wlan0: soliciting an IPv6 router Apr 17 10:45:26 volumio dhcpcd[811]: wlan0: rebinding lease of 192.168.0.3 Apr 17 10:45:26 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Apr 17 10:45:26 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:26 volumio volumio[1615]: Starting albumart workers Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::pushState Apr 17 10:45:26 volumio volumio[1615]: info: CorePlayQueue::getTrack 0 Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::volumioPushState Apr 17 10:45:26 volumio dhcpcd[811]: wlan0: probing address 192.168.0.3/24 Apr 17 10:45:26 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:26 volumio go-librespot[1934]: go-librespot daemon starting... Apr 17 10:45:26 volumio go-librespot[1934]: time="2025-04-17T10:45:26-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:26 volumio go-librespot[1934]: time="2025-04-17T10:45:26-03:00" level=debug msg="app state loaded" Apr 17 10:45:26 volumio go-librespot[1934]: time="2025-04-17T10:45:26-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:26 volumio go-librespot[1934]: time="2025-04-17T10:45:26-03: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" Apr 17 10:45:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:26 volumio volumio[1615]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Apr 17 10:45:26 volumio volumio[1615]: Starting albumart workers Apr 17 10:45:26 volumio volumio[1615]: info: Reloading queue from file Apr 17 10:45:26 volumio volumio[1615]: Starting albumart workers Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::setRepeat null single undefined Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::pushState Apr 17 10:45:26 volumio volumio[1615]: info: CorePlayQueue::getTrack 0 Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::volumioPushState Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::setRandom null Apr 17 10:45:26 volumio volumio[1615]: info: CoreStateMachine::pushState Apr 17 10:45:26 volumio volumio[1615]: info: CorePlayQueue::getTrack 0 Apr 17 10:45:26 volumio volumio[1615]: info: CoreCommandRouter::volumioPushState Apr 17 10:45:26 volumio volumio[1615]: info: Setting Device type: Raspberry PI Apr 17 10:45:26 volumio volumio[1615]: info: Discovery: A device disappeared from network Apr 17 10:45:26 volumio volumio[1615]: info: Discovery: Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Apr 17 10:45:27 volumio sudo[1947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 17 10:45:27 volumio sudo[1947]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:27 volumio sudo[1947]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:27 volumio volumio[1615]: info: Upmpdcli Daemon Started Apr 17 10:45:27 volumio volumio[1615]: info: Completed loading Core Plugins Apr 17 10:45:27 volumio volumio[1615]: info: Preparing to generate the ALSA configuration file Apr 17 10:45:27 volumio volumio[1615]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Apr 17 10:45:27 volumio volumio[1615]: info: Reading ALSA contributions from plugins. Apr 17 10:45:27 volumio volumio[1615]: info: Asound.conf file unchanged, so no further update is needed Apr 17 10:45:27 volumio volumio[1615]: info: Output device has changed, restarting MPD Apr 17 10:45:27 volumio volumio[1615]: info: Output device has changed, restarting Shairport Sync Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:45:27 volumio sudo[1950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:45:27 volumio sudo[1950]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:27 volumio sudo[1950]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:27 volumio sudo[1952]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:45:27 volumio sudo[1952]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:27 volumio volumio[1615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:45:27 volumio volumio[1615]: info: ___________ START PLUGINS ___________ Apr 17 10:45:27 volumio volumio[1615]: info: ControllerMpd::onStart: Initializing MPD Apr 17 10:45:27 volumio volumio[1615]: info: Creating MPD Configuration file Apr 17 10:45:27 volumio systemd[1]: Stopping Music Player Daemon... Apr 17 10:45:27 volumio ntpd[659]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:27 volumio volumio[1615]: info: [1744897527725] CoreMusicLibrary::Adding element Servidores multimédia Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:27 volumio sudo[1959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 17 10:45:27 volumio sudo[1959]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:27 volumio sudo[1961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 17 10:45:27 volumio sudo[1961]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:27 volumio sudo[1959]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:27 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:45:27 volumio systemd[1]: mpd.service: Succeeded. Apr 17 10:45:27 volumio systemd[1]: Stopped Music Player Daemon. Apr 17 10:45:27 volumio systemd[1]: Starting Music Player Daemon... Apr 17 10:45:28 volumio volumio[1615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:45:28 volumio volumio[1615]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:28 volumio volumio[1615]: info: [1744897528188] CoreMusicLibrary::Adding element Last_100 Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:28 volumio volumio[1615]: info: [1744897528198] CoreMusicLibrary::Adding element Webradio Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:45:28 volumio volumio[1615]: info: Initializing BBC Radios Apr 17 10:45:28 volumio sudo[1975]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 17 10:45:28 volumio sudo[1975]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 10:45:28 volumio sudo[1975]: pam_unix(sudo:session): session closed for user root Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:28 volumio volumio[1615]: info: [1744897528528] CoreMusicLibrary::Adding element Bandcamp Discover Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source Bandcamp Discover Apr 17 10:45:28 volumio wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Apr 17 10:45:28 volumio volumio[1615]: info: Creating Spotify config file Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:28 volumio volumio[1615]: info: [1744897528862] CoreMusicLibrary::Adding element YouTube Music Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source Bandcamp Discover Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source YouTube Music Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 17 10:45:28 volumio volumio[1615]: info: [1744897528884] CoreMusicLibrary::Adding element LastFM Apr 17 10:45:28 volumio volumio[1615]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source Bandcamp Discover Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source YouTube Music Apr 17 10:45:28 volumio volumio[1615]: Cannot find translation for source LastFM Apr 17 10:45:28 volumio volumio[1615]: info: [LastFM] scrobbler initiated! Apr 17 10:45:28 volumio volumio[1615]: info: [LastFM] extended logging: false Apr 17 10:45:28 volumio volumio[1615]: info: [LastFM] try scrobble stream/radio plays: true Apr 17 10:45:28 volumio volumio[1615]: info: [LastFM] Left init routine Apr 17 10:45:28 volumio volumio[1615]: info: [LastFM] Socket already connected: true Apr 17 10:45:28 volumio volumio[1615]: info: Volumio Calling Home Apr 17 10:45:29 volumio volumio[1615]: Unhandled rejection Error: No sockets available, cannot start. Apr 17 10:45:29 volumio volumio[1615]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Apr 17 10:45:29 volumio volumio[1615]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Apr 17 10:45:29 volumio volumio[1615]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Apr 17 10:45:29 volumio volumio[1615]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Apr 17 10:45:29 volumio volumio[1615]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Apr 17 10:45:29 volumio volumio[1615]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Apr 17 10:45:29 volumio volumio[1615]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Apr 17 10:45:29 volumio volumio[1615]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Apr 17 10:45:29 volumio volumio[1615]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Apr 17 10:45:29 volumio volumio[1615]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Apr 17 10:45:29 volumio volumio[1615]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Apr 17 10:45:29 volumio volumio[1615]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Apr 17 10:45:29 volumio volumio[1615]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Apr 17 10:45:29 volumio volumio[1615]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Apr 17 10:45:29 volumio volumio[1615]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Apr 17 10:45:29 volumio volumio[1615]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 17 10:45:29 volumio volumio[1615]: info: An error occurred while refreshing Spotify Token Error: getaddrinfo EBUSY oauth-performer.prod.vlmapi.io Apr 17 10:45:29 volumio volumio[1615]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:45:29 volumio volumio[1615]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Apr 17 10:45:29 volumio volumio[1615]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Apr 17 10:45:29 volumio volumio[1615]: errno: -16, Apr 17 10:45:29 volumio volumio[1615]: code: 'EBUSY', Apr 17 10:45:29 volumio volumio[1615]: syscall: 'getaddrinfo', Apr 17 10:45:29 volumio volumio[1615]: hostname: 'ws.audioscrobbler.com' Apr 17 10:45:29 volumio volumio[1615]: } Apr 17 10:45:29 volumio volumio[1615]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 10:45:29 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Apr 17 10:45:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Apr 17 10:45:29 volumio systemd[1]: Stopped go-librespot Daemon. Apr 17 10:45:29 volumio systemd[1]: Started go-librespot Daemon. Apr 17 10:45:29 volumio go-librespot[2032]: go-librespot daemon starting... Apr 17 10:45:29 volumio go-librespot[2032]: time="2025-04-17T10:45:29-03:00" level=info msg="running go-librespot 0.2.0" Apr 17 10:45:29 volumio go-librespot[2032]: time="2025-04-17T10:45:29-03:00" level=debug msg="app state loaded" Apr 17 10:45:29 volumio go-librespot[2032]: time="2025-04-17T10:45:29-03:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 17 10:45:29 volumio go-librespot[2032]: time="2025-04-17T10:45:29-03: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" Apr 17 10:45:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Apr 17 10:45:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Apr 17 10:45:30 volumio volumio-time-update[496]: volumio-time-update-util: Fetching time from Volumio... Apr 17 10:45:30 volumio volumio-time-update[496]: volumio-time-update-util: Date not found in response Apr 17 10:45:30 volumio volumio-time-update[496]: volumio-time-update-util: Retrying in 5 seconds... Apr 17 10:45:30 volumio sudo[2045]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-17 10:44 Apr 17 10:45:30 volumio sudo[2045]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"