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