-- Logs begin at Tue 2022-07-19 18:58:21 UTC, end at Tue 2025-07-08 19:46:39 UTC. -- Jul 08 19:46:18 shd systemd[1]: Time has been changed Jul 08 19:46:19 shd volumio[944]: info: Applying required configuration parameters for plugin ms_surface_dial Jul 08 19:46:19 shd volumio[944]: info: Plugin example_plugin is not enabled Jul 08 19:46:19 shd volumio[944]: info: Loading plugin "hi_res_audio"... Jul 08 19:46:19 shd volumio[944]: info: Applying required configuration parameters for plugin hi_res_audio Jul 08 19:46:19 shd volumio[944]: info: Loading plugin "inputs"... Jul 08 19:46:19 shd volumio[944]: info: Loading plugin "qobuz"... Jul 08 19:46:19 shd sudo[980]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:19 shd volumio-remote-updater[643]: [2025-07-08 19:46:19] [connect] Successful connection Jul 08 19:46:19 shd volumio[944]: Starting albumart workers Jul 08 19:46:19 shd volumio[944]: Starting albumart workers Jul 08 19:46:19 shd volumio[944]: Starting albumart workers Jul 08 19:46:22 shd volumio[944]: info: Loading plugin "tidal"... Jul 08 19:46:24 shd volumio[944]: info: Loading plugin "updater_comm"... Jul 08 19:46:24 shd volumio[944]: info: Plugin mpdemulation is not enabled Jul 08 19:46:24 shd volumio[944]: info: Loading plugin "rest_api"... Jul 08 19:46:24 shd volumio[944]: info: Loading plugin "websocket"... Jul 08 19:46:24 shd volumio[944]: info: Loading plugin "RoonBridge"... Jul 08 19:46:25 shd ifup[516]: dhcpcd[550]: timed out Jul 08 19:46:25 shd dhcpcd[550]: timed out Jul 08 19:46:25 shd dhcpcd[550]: exited Jul 08 19:46:25 shd ifup[516]: dhcpcd[550]: exited Jul 08 19:46:25 shd ifup[516]: Failed to bring up eth0. Jul 08 19:46:25 shd volumio[944]: info: Applying required configuration parameters for plugin RoonBridge Jul 08 19:46:25 shd volumio[944]: info: Loading plugin "spop"... Jul 08 19:46:27 shd volumio[944]: info: Loading plugin "volspotconnect2"... Jul 08 19:46:28 shd volumio[944]: info: ___________ START PLUGINS ___________ Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 08 19:46:28 shd volumio[944]: info: [1752003988016] CoreMusicLibrary::Adding element Media Servers Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 08 19:46:28 shd volumio[944]: info: Adding METAVOLUMIO REST API Endpoints Jul 08 19:46:28 shd volumio[944]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Jul 08 19:46:28 shd sudo[1041]: pam_unix(sudo:auth): conversation failed Jul 08 19:46:28 shd sudo[1041]: pam_unix(sudo:auth): auth could not identify password for [volumio] Jul 08 19:46:28 shd volumio[944]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 08 19:46:28 shd volumio[944]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 08 19:46:28 shd volumio[944]: info: Preparing CD Folders Jul 08 19:46:28 shd volumio[944]: info: Adding CD REST API Endpoints Jul 08 19:46:28 shd volumio[944]: info: Adding detectCD REST Endpoint for plugin: music_service/cd_controller Jul 08 19:46:28 shd volumio[944]: info: Adding cdRemove REST Endpoint for plugin: music_service/cd_controller Jul 08 19:46:28 shd volumio[944]: info: Adding cdPostScan REST Endpoint for plugin: music_service/cd_controller Jul 08 19:46:28 shd volumio[944]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Jul 08 19:46:28 shd volumio[944]: info: Detecting CD presence with Flag file Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 08 19:46:28 shd volumio[944]: info: [1752003988204] CoreMusicLibrary::Adding element Last_100 Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:28 shd volumio[944]: info: Starting RAAT Plugin Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Jul 08 19:46:28 shd volumio[944]: info: Additional UI Settings Added for plugin music_service/raat Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: Not Reporting Auto name since its the default one Jul 08 19:46:28 shd volumio[944]: info: Streaming services startup Jul 08 19:46:28 shd volumio[944]: info: Starting Streaming Daemon Jul 08 19:46:28 shd sudo[1055]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jul 08 19:46:28 shd sudo[1055]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:28 shd systemd[1]: Stopping Volumio Streaming Daemon... Jul 08 19:46:28 shd systemd[1]: Starting Volumio Streaming Daemon... Jul 08 19:46:28 shd systemd[1]: Started Volumio Streaming Daemon. Jul 08 19:46:28 shd sudo[1055]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: ############################ Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: # Volumio Streaming Daemon # Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: # Running on port 7777 # Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: ############################ Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: Checking variant in static cache Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: Enabled services: Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: 1) tidal Jul 08 19:46:28 shd volumio-streaming-daemon[1060]: 2) qobuz Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 08 19:46:28 shd volumio[944]: info: [1752003988391] CoreMusicLibrary::Adding element Webradio Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 08 19:46:28 shd volumio[944]: error: Hi Res Audio Failed Login: Missing Login Data Jul 08 19:46:28 shd volumio[944]: info: Refreshing QOBUZ token Jul 08 19:46:28 shd sudo[1069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jul 08 19:46:28 shd sudo[1069]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:28 shd systemd[1]: Starting RoonBridge... Jul 08 19:46:28 shd systemd[1]: Started RoonBridge. Jul 08 19:46:28 shd sudo[1069]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jul 08 19:46:28 shd sudo[1077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Jul 08 19:46:28 shd sudo[1077]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:28 shd sudo[1077]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:28 shd volumio[944]: [SpotifyConnect] Creating VLS config file Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: [SpotifyConnect] Starting metadata listener Jul 08 19:46:28 shd volumio[944]: [SpotifyConnect] Creating VLS config file Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: [SpotifyConnect] <> or Mixer found, using softvol Jul 08 19:46:28 shd sudo[1083]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Jul 08 19:46:28 shd volumio[944]: [SpotifyConnect] Starting metadata listener Jul 08 19:46:28 shd sudo[1083]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:28 shd systemd[1]: Starting Volspotconnect2 Daemon... Jul 08 19:46:28 shd systemd[1]: Started Volspotconnect2 Daemon. Jul 08 19:46:28 shd sudo[1083]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:28 shd volumio[944]: info: Loading i18n strings for locale en Jul 08 19:46:28 shd sudo[1087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Jul 08 19:46:28 shd sudo[1087]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:28 shd volumio[944]: Updating browse sources language Jul 08 19:46:28 shd volumio[944]: Cannot find translation for sourceMedia Servers Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:28 shd systemd[1]: Starting Volspotconnect2 Daemon... Jul 08 19:46:28 shd systemd[1]: Started Volspotconnect2 Daemon. Jul 08 19:46:28 shd sudo[1087]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::initPlayerControls Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 08 19:46:28 shd volumio[944]: info: BOOT COMPLETED Jul 08 19:46:28 shd volumio[944]: [Metrics] CommandRouter: 17s 719.37ms Jul 08 19:46:28 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 08 19:46:29 shd volumio[1086]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Jul 08 19:46:29 shd volumio[1086]: Reading Config from "/tmp/volspotify.toml" Jul 08 19:46:29 shd volumio[1086]: Malformed config key: missing field `Authentication` Jul 08 19:46:29 shd volumio[1090]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Jul 08 19:46:29 shd volumio[1090]: Reading Config from "volspotify.toml" Jul 08 19:46:29 shd volumio[1090]: [Vollibrespot] : Using Alsa backend with device: plughw:0 Jul 08 19:46:29 shd volumio[1090]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Jul 08 19:46:30 shd RoonBridge[1071]: 00:00:00.018 Warn: get lock file path: /tmp/.rnbgem0- Jul 08 19:46:31 shd systemd[1]: volspotconnect.service holdoff time over, scheduling restart. Jul 08 19:46:31 shd systemd[1]: Stopping Volspotconnect2 Daemon... Jul 08 19:46:31 shd systemd[1]: Starting Volspotconnect2 Daemon... Jul 08 19:46:31 shd systemd[1]: Started Volspotconnect2 Daemon. Jul 08 19:46:31 shd volumio[1099]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Jul 08 19:46:31 shd volumio[1099]: Reading Config from "/tmp/volspotify.toml" Jul 08 19:46:31 shd volumio[1099]: Malformed config key: missing field `Authentication` Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:00.803 Trace: [childprocess] using unix child process Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:00.911 Debug: PathForResource, filename: ../.update Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.020 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.032 Debug: PathForResource, filename: RAATServer Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.032 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.034 Debug: PathForResource, filename: RoonBridgeHelper Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.034 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Jul 08 19:46:31 shd RoonBridge[1071]: Initializing Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.102 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Jul 08 19:46:31 shd RoonBridge[1071]: 00:00:01.168 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Jul 08 19:46:31 shd RoonBridge[1071]: Not Running (.o) Jul 08 19:46:32 shd RoonBridge[1071]: Running Jul 08 19:46:33 shd RoonBridge[1071]: 00:00:00.055 Warn: get lock file path: /tmp/.rnbhgem0- Jul 08 19:46:33 shd systemd[1]: volspotconnect.service holdoff time over, scheduling restart. Jul 08 19:46:33 shd systemd[1]: Stopping Volspotconnect2 Daemon... Jul 08 19:46:33 shd systemd[1]: Starting Volspotconnect2 Daemon... Jul 08 19:46:33 shd systemd[1]: Started Volspotconnect2 Daemon. Jul 08 19:46:33 shd volumio[1128]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Jul 08 19:46:33 shd volumio[1128]: Reading Config from "/tmp/volspotify.toml" Jul 08 19:46:33 shd volumio[1128]: Malformed config key: missing field `Authentication` Jul 08 19:46:34 shd volumio[944]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::Close All Modals sent Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::Close All Modals sent Jul 08 19:46:34 shd volumio[944]: Express server listening on port 3000 Jul 08 19:46:34 shd volumio[944]: [Metrics] WebUI: 24s 398.71ms Jul 08 19:46:34 shd volumio[944]: Volumio Calling Home Jul 08 19:46:34 shd volumio[944]: [SpotifyConnect] Error: bind EADDRINUSE 0.0.0.0:5030 Jul 08 19:46:34 shd volumio[944]: at _handle.lookup (dgram.js:266:18) Jul 08 19:46:34 shd volumio[944]: at _combinedTickCallback (internal/process/next_tick.js:142:11) Jul 08 19:46:34 shd volumio[944]: at process._tickCallback (internal/process/next_tick.js:181:9) Jul 08 19:46:34 shd volumio[944]: at Function.Module.runMain (module.js:696:11) Jul 08 19:46:34 shd volumio[944]: at startup (bootstrap_node.js:204:16) Jul 08 19:46:34 shd volumio[944]: at bootstrap_node.js:625:3 Jul 08 19:46:34 shd volumio[944]: [SpotifyConnect] Error [ERR_SOCKET_CANNOT_SEND]: Unable to send data Jul 08 19:46:34 shd volumio[944]: at Socket.onListenError (dgram.js:362:22) Jul 08 19:46:34 shd volumio[944]: at Object.onceWrapper (events.js:315:30) Jul 08 19:46:34 shd volumio[944]: at emitOne (events.js:121:20) Jul 08 19:46:34 shd volumio[944]: at Socket.emit (events.js:211:7) Jul 08 19:46:34 shd volumio[944]: at _handle.lookup (dgram.js:267:14) Jul 08 19:46:34 shd volumio[944]: at _combinedTickCallback (internal/process/next_tick.js:142:11) Jul 08 19:46:34 shd volumio[944]: at process._tickCallback (internal/process/next_tick.js:181:9) Jul 08 19:46:34 shd volumio[944]: at Function.Module.runMain (module.js:696:11) Jul 08 19:46:34 shd volumio[944]: at startup (bootstrap_node.js:204:16) Jul 08 19:46:34 shd volumio[944]: at bootstrap_node.js:625:3 Jul 08 19:46:34 shd volumio[944]: info: CoreStateMachine::resetVolumioState Jul 08 19:46:34 shd volumio[944]: info: CoreStateMachine::getcurrentVolume Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::volumioRetrievevolume Jul 08 19:46:34 shd volumio[944]: info: Stopping AccessToken refresher cron Jul 08 19:46:34 shd volumio[944]: info: AccessToken refresher cron started Jul 08 19:46:34 shd volumio[944]: info: msSurfaceDial volumioupdatevolume callback: {"vol":100,"mute":false,"disableVolumeControl":true} Jul 08 19:46:34 shd volumio[944]: info: CoreStateMachine::pushState Jul 08 19:46:34 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::volumioPushState Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 19:46:34 shd volumio-remote-updater[643]: [2025-07-08 19:46:34] [connect] Successful connection Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 08 19:46:34 shd sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 08 19:46:34 shd sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:34 shd sudo[1142]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:34 shd sudo[1143]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 08 19:46:34 shd sudo[1143]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:34 shd sudo[1143]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:34 shd sudo[1146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Jul 08 19:46:34 shd sudo[1146]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:34 shd systemd[1]: Configuration file /lib/systemd/system/volumiobt.service is marked executable. Please remove executable permission bits. Proceeding anyway. Jul 08 19:46:34 shd systemd[1]: Starting Volumio Bluetooth Module... Jul 08 19:46:34 shd systemd[1]: Started Volumio Bluetooth Module. Jul 08 19:46:34 shd sudo[1146]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:34 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:34 shd sudo[1150]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Jul 08 19:46:34 shd sudo[1150]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:34 shd volumiobt[1149]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Jul 08 19:46:34 shd sudo[1150]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:34 shd volumio[944]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jul 08 19:46:34 shd volumio[944]: info: Serial port opened successfully Jul 08 19:46:35 shd volumio[944]: info: Volumio BT Module successfully started Jul 08 19:46:35 shd volumio[944]: info: Setting Device type: NanoPi NEO2 Jul 08 19:46:35 shd volumio[944]: [SpotifyConnect] Vollibrespot Daemon service started! Jul 08 19:46:35 shd volumio[944]: [Metrics] SpotifyConnect: 6s 521.80ms Jul 08 19:46:35 shd volumio[944]: [SpotifyConnect] Vollibrespot Daemon service started! Jul 08 19:46:35 shd volumio[944]: [Metrics] SpotifyConnect: 6s 524.73ms Jul 08 19:46:35 shd volumio[944]: info: RAAT Albumart path created successfully Jul 08 19:46:35 shd volumio[944]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'shd' Jul 08 19:46:35 shd volumio[944]: sudo: no tty present and no askpass program specified Jul 08 19:46:35 shd volumio[944]: info: Cannot mount NAS Music at system boot, trial number 1 ,retrying in 5 seconds Jul 08 19:46:35 shd volumio[944]: info: MPD running with PID670 Jul 08 19:46:35 shd volumio[944]: ,establishing connection Jul 08 19:46:35 shd sudo[1155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/sbin/i2cdetect -y 1 Jul 08 19:46:35 shd sudo[1155]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:35 shd sudo[1155]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:35 shd dbus[674]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' Jul 08 19:46:35 shd systemd[1]: Starting Bluetooth service... Jul 08 19:46:35 shd bluetoothd[1157]: Bluetooth daemon 5.23 Jul 08 19:46:35 shd dbus[674]: [system] Successfully activated service 'org.bluez' Jul 08 19:46:35 shd systemd[1]: Started Bluetooth service. Jul 08 19:46:35 shd kernel: Bluetooth: Core ver 2.22 Jul 08 19:46:35 shd kernel: NET: Registered protocol family 31 Jul 08 19:46:35 shd kernel: Bluetooth: HCI device and connection manager initialized Jul 08 19:46:35 shd kernel: Bluetooth: HCI socket layer initialized Jul 08 19:46:35 shd kernel: Bluetooth: L2CAP socket layer initialized Jul 08 19:46:35 shd kernel: Bluetooth: SCO socket layer initialized Jul 08 19:46:35 shd bluetoothd[1157]: Starting SDP server Jul 08 19:46:35 shd bluetoothd[1157]: Excluding (cli) sap Jul 08 19:46:35 shd volumio-remote-updater[643]: [2025-07-08 19:46:35] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.5.1" /socket.io/?EIO=4&transport=websocket&t=1752003994 101 Jul 08 19:46:35 shd kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 Jul 08 19:46:35 shd kernel: Bluetooth: BNEP filters: protocol multicast Jul 08 19:46:35 shd kernel: Bluetooth: BNEP socket layer initialized Jul 08 19:46:35 shd bluetoothd[1157]: Bluetooth management interface 1.14 initialized Jul 08 19:46:35 shd dbus[674]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' Jul 08 19:46:35 shd volumio[944]: info: Volumio called home Jul 08 19:46:35 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jul 08 19:46:35 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 08 19:46:35 shd systemd[1]: Starting Hostname Service... Jul 08 19:46:35 shd volumio[944]: xcb_connection_has_error() returned true Jul 08 19:46:35 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jul 08 19:46:35 shd systemd-hostnamed[1163]: Warning: nss-myhostname is not installed. Changing the local hostname might make it unresolveable. Please install nss-myhostname! Jul 08 19:46:35 shd dbus[674]: [system] Successfully activated service 'org.freedesktop.hostname1' Jul 08 19:46:35 shd systemd[1]: volspotconnect.service holdoff time over, scheduling restart. Jul 08 19:46:35 shd systemd[1]: Started Hostname Service. Jul 08 19:46:35 shd systemd[1]: Stopping Volspotconnect2 Daemon... Jul 08 19:46:35 shd systemd[1]: Starting Volspotconnect2 Daemon... Jul 08 19:46:35 shd systemd[1]: Started Volspotconnect2 Daemon. Jul 08 19:46:35 shd volumio[1165]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Jul 08 19:46:35 shd volumio[1165]: Reading Config from "/tmp/volspotify.toml" Jul 08 19:46:35 shd volumio[1165]: [Vollibrespot] : Using Alsa backend with device: plughw:0 Jul 08 19:46:35 shd volumio[1165]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Jul 08 19:46:35 shd volumio[944]: info: Cannot read I2C interface or I2C interface not presentError: Command failed: /usr/bin/sudo /usr/sbin/i2cdetect -y 1 Jul 08 19:46:35 shd volumio[944]: Error: Could not open file `/dev/i2c-1' or `/dev/i2c/1': No such file or directory Jul 08 19:46:35 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jul 08 19:46:35 shd sudo[1175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Jul 08 19:46:35 shd sudo[1175]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:36 shd volumio[944]: xcb_connection_has_error() returned true Jul 08 19:46:36 shd volumiobt[1149]: pulseaudio: no process found Jul 08 19:46:36 shd sudo[1175]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:36 shd volumio[944]: info: Reloading queue from file Jul 08 19:46:36 shd volumio[944]: info: Serial Data: Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: raat , reconfigureAndRestartRaat Jul 08 19:46:36 shd volumio[944]: info: Reconfiguring and Restarting RAAT Plugin Jul 08 19:46:36 shd sudo[1181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jul 08 19:46:36 shd sudo[1181]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:36 shd systemd[1]: Starting RAAT DAEMON... Jul 08 19:46:36 shd systemd[1]: Started RAAT DAEMON. Jul 08 19:46:36 shd sudo[1181]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 08 19:46:36 shd volumio[944]: info: Not Reporting Auto name since its the default one Jul 08 19:46:36 shd volumio[944]: info: RAAT Overriding default device vendor model Jul 08 19:46:36 shd volumio[944]: info: Adding MINIDSP Inputs Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 08 19:46:36 shd volumio[944]: info: [1752003996206] CoreMusicLibrary::Adding element Inputs Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:36 shd dbus[674]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' Jul 08 19:46:36 shd systemd[1]: Starting RealtimeKit Scheduling Policy Service... Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 08 19:46:36 shd volumio[944]: info: [1752003996264] CoreMusicLibrary::Adding element Presets Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:36 shd volumio[944]: info: msSurfaceDial Managed Objs {"/org/bluez":{"org.freedesktop.DBus.Introspectable":{},"org.bluez.AgentManager1":{},"org.bluez.ProfileManager1":{},"org.bluez.Alert1":{},"org.bluez.HealthManager1":{}}} Jul 08 19:46:36 shd volumio[944]: info: [msSurfaceDial init()] check /org/bluez Jul 08 19:46:36 shd volumio[944]: info: [msSurfaceDial init()] Adapter: null; SurfaceDial: null Jul 08 19:46:36 shd dbus[674]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Jul 08 19:46:36 shd systemd[1]: Started RealtimeKit Scheduling Policy Service. Jul 08 19:46:36 shd rtkit-daemon[1200]: Successfully called chroot. Jul 08 19:46:36 shd rtkit-daemon[1200]: Successfully dropped privileges. Jul 08 19:46:36 shd rtkit-daemon[1200]: Successfully limited resources. Jul 08 19:46:36 shd rtkit-daemon[1200]: Running. Jul 08 19:46:36 shd rtkit-daemon[1200]: Watchdog thread running. Jul 08 19:46:36 shd volumio[944]: info: msSurfaceDial BluetoothSurfaceDial init() - ready! Jul 08 19:46:36 shd volumio[944]: info: CoreCommandRouter::Reload Ui Jul 08 19:46:36 shd volumio[944]: ------------------------------------ BT MESSAGE: BT STATUS: running Jul 08 19:46:36 shd rtkit-daemon[1200]: Canary thread running. Jul 08 19:46:36 shd volumio[944]: ------------------------------------ BT MESSAGE: BT STATUS: running Jul 08 19:46:36 shd volumio[944]: error: updateQueue error: null Jul 08 19:46:36 shd volumio[944]: error: Failed LSINFO: Error: [50@0] {} No such directory Jul 08 19:46:36 shd pulseaudio[1194]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jul 08 19:46:36 shd pulseaudio[1194]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Jul 08 19:46:36 shd pulseaudio[1194]: org.bluez.Manager.GetProperties() failed: org.freedesktop.DBus.Error.UnknownMethod: Method "GetProperties" with signature "" on interface "org.bluez.Manager" doesn't exist Jul 08 19:46:36 shd volumiobt[1149]: Applying permissions Jul 08 19:46:36 shd volumiobt[1149]: Setting BT discoverable and pairable Jul 08 19:46:36 shd volumiobt[1149]: [38B blob data] Jul 08 19:46:36 shd volumiobt[1149]: Invalid command Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# agent on Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# discoverable on Jul 08 19:46:36 shd volumiobt[1149]: No default controller available Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# pairable on Jul 08 19:46:36 shd volumiobt[1149]: No default controller available Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# agent NoInputNoOutput Jul 08 19:46:36 shd volumiobt[1149]: Failed to register agent object Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# default-agent Jul 08 19:46:36 shd volumiobt[1149]: No agent is registered Jul 08 19:46:36 shd volumiobt[1149]: [bluetooth]# quit Jul 08 19:46:36 shd volumiobt[1149]: [61B blob data] Jul 08 19:46:36 shd volumiobt[1149]: [62B blob data] Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::setRepeat undefined single undefined Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::pushState Jul 08 19:46:37 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioPushState Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::setRandom true Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::pushState Jul 08 19:46:37 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioPushState Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 19:46:37 shd volumio[944]: info: Raat Daemon started successfully Jul 08 19:46:37 shd volumio[944]: info: mDNS: A device disapperared from network Jul 08 19:46:37 shd volumio[944]: info: mDNS Browse raised the following error TypeError: Cannot read property 'toLowerCase' of undefined Jul 08 19:46:37 shd volumio[944]: info: Executing endpoint restartRAATSocket Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jul 08 19:46:37 shd volumio[944]: info: Starting Shairport Sync Jul 08 19:46:37 shd volumio[944]: info: Starting Shairport Sync Jul 08 19:46:37 shd sudo[1220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 08 19:46:37 shd sudo[1220]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:37 shd systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Jul 08 19:46:37 shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 08 19:46:37 shd volumio[944]: info: Serial Data: Jul 08 19:46:37 shd sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 08 19:46:37 shd sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:37 shd sudo[1220]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:37 shd volumio[944]: info: msSurfaceDial volumioupdatevolume callback: {"mute":false,"disableVolumeControl":false} Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::pushState Jul 08 19:46:37 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioPushState Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Jul 08 19:46:37 shd systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 08 19:46:37 shd volumio[944]: info: Updating RAAT Signal Path Jul 08 19:46:37 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumiosetSourceActiveno-source Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 08 19:46:37 shd sudo[1226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jul 08 19:46:37 shd sudo[1226]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioStop Jul 08 19:46:37 shd systemd[1]: Starting Shairport Sync - AirPlay Audio Receiver... Jul 08 19:46:37 shd systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 08 19:46:37 shd sudo[1223]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::stop Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 19:46:37 shd volumio[944]: verbose: UNSET VOLATILE Jul 08 19:46:37 shd volumio[944]: info: Notifying Active Input {"trackType":"input","service":"inputs","title":"TOSLINK","disableUiControls":true,"albumart":"/albumart"} Jul 08 19:46:37 shd volumio[944]: info: msSurfaceDial volumioupdatevolume callback: {"vol":null,"dbVolume":null,"mute":false,"disableVolumeControl":false} Jul 08 19:46:37 shd systemd[1]: Starting UPnP Renderer front-end to MPD... Jul 08 19:46:37 shd systemd[1]: Started UPnP Renderer front-end to MPD. Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::pushState Jul 08 19:46:37 shd volumio[944]: info: CorePlayQueue::getTrack 0 Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioPushState Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 08 19:46:37 shd sudo[1226]: pam_unix(sudo:session): session closed for user root Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Jul 08 19:46:37 shd volumio[944]: info: Updating RAAT Signal Path Jul 08 19:46:37 shd volumio[944]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 08 19:46:37 shd volumio[944]: Discovery: adding c96094bd-a322-465c-98e6-a51c19ab2527 Jul 08 19:46:37 shd volumio[944]: info: mDNS: Found device shd Jul 08 19:46:37 shd volumio[944]: info: CoreCommandRouter::volumioGetState Jul 08 19:46:37 shd volumio[944]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 19:46:37 shd volumio[944]: Error: The value NaN is not a number Jul 08 19:46:37 shd volumio[944]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Jul 08 19:46:37 shd volumio[944]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Jul 08 19:46:37 shd volumio[944]: at ControllerVolumioDiscovery.pushMultiRoomStatusUpdate (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:287:25) Jul 08 19:46:38 shd volumio[944]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:276:10) Jul 08 19:46:38 shd volumio[944]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:202:12) Jul 08 19:46:38 shd volumio[944]: at emitTwo (events.js:126:13) Jul 08 19:46:38 shd volumio[944]: at Browser.emit (events.js:214:7) Jul 08 19:46:38 shd volumio[944]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Jul 08 19:46:38 shd volumio[944]: at next (/volumio/node_modules/mdns/lib/browser.js:104:7) Jul 08 19:46:38 shd volumio[944]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Jul 08 19:46:38 shd volumio[944]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Jul 08 19:46:38 shd volumio[944]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Jul 08 19:46:38 shd volumio[944]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 08 19:46:39 shd sudo[1257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-08 19:45 Jul 08 19:46:39 shd sudo[1257]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 8 (jessie)" NAME="Debian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" ID=debian HOME_URL="http://www.debian.org/" SUPPORT_URL="http://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03" VOLUMIO_FE_VERSION="e5ce74e254a237ac98580c4437c4ed223c7d5cd9" VOLUMIO_BE_VERSION="0cf482c24e7a7ab87af1081ea7d6d953621249a4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Mar 23 10:08:04 CET 2022" VOLUMIO_VERSION="1.121" VOLUMIO_HARDWARE="nanopineo2" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="c49a059c2bcfb892c670d4f5a84421ae"