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