May 19 16:51:01 smx systemd[1]: systemd-timedated.service: Deactivated successfully. May 19 16:52:11 smx systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 19 16:52:11 smx dbus-daemon[946]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.1562' (uid=0 pid=108503 comm="timedatectl show --property=NTPSynchronized --valu") May 19 16:52:11 smx systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 19 16:52:11 smx dbus-daemon[946]: [system] Successfully activated service 'org.freedesktop.timedate1' May 19 16:52:11 smx systemd[1]: Started systemd-timedated.service - Time & Date Service. May 19 16:52:11 smx setdatetime-helper.sh[108502]: Time is already synchronized. May 19 16:52:11 smx systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 19 16:52:11 smx systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 19 16:52:35 smx sudo[108550]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 19 16:52:35 smx sudo[108550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:35 smx sudo[108550]: pam_unix(sudo:session): session closed for user root May 19 16:52:35 smx sudo[108552]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 19 16:52:35 smx sudo[108552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:35 smx sudo[108552]: pam_unix(sudo:session): session closed for user root May 19 16:52:35 smx volumio[1133]: verbose: New Socket.io Connection to 192.168.178.37 from 192.168.178.45 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::volumioGetVisibleSources May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 19 16:52:35 smx volumio[1133]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom May 19 16:52:35 smx volumio[1133]: info: Received Get System Info May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 19 16:52:35 smx volumio[1133]: info: Discovery: Getting this device information May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:35 smx volumio[1133]: info: Listing playlists May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 19 16:52:35 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 19 16:52:36 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 19 16:52:37 smx volumio[1133]: info: Received Get System Info May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 19 16:52:37 smx volumio[1133]: info: Discovery: Getting this device information May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:37 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 19 16:52:38 smx volumio[1133]: info: Executing endpoint metavolumio May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 19 16:52:38 smx volumio[1133]: info: Executing endpoint metavolumio May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 19 16:52:38 smx volumio[1133]: info: Executing endpoint metavolumio May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 19 16:52:38 smx volumio[1133]: info: Received Get System Info May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 19 16:52:38 smx volumio[1133]: info: Discovery: Getting this device information May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::volumioGetState May 19 16:52:38 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: Retrieving Cloud Streaming UI May 19 16:52:39 smx volumio[1133]: info: Getting Tidal Cloud Configuration May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: Getting Qobuz Cloud Configuration May 19 16:52:39 smx volumio[1133]: info: Asking plugin for UI Config May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: Getting Spotify Cloud Configuration May 19 16:52:39 smx volumio[1133]: info: Asking plugin for UI Config May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: Saving Spotify Acccount May 19 16:52:39 smx volumio[1133]: info: Got it May 19 16:52:39 smx volumio[1133]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 19 16:52:39 smx volumio[1133]: info: Got Tidal Cloud Configuration May 19 16:52:39 smx volumio[1133]: info: Got it May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::getUIConfigOnPlugin May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::volumioGetBrowseSources May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::volumioGetBrowseSources May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::volumioGetBrowseSources May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 19 16:52:39 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 19 16:52:41 smx systemd[1]: systemd-timedated.service: Deactivated successfully. May 19 16:52:43 smx nmbd[1118]: [2025/05/19 16:52:43.690098, 0] ../../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 19 16:52:43 smx nmbd[1118]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.178.37 for name WORKGROUP<1d>. May 19 16:52:43 smx nmbd[1118]: This response was from IP 192.168.178.44, reporting an IP address of 192.168.178.44. May 19 16:52:43 smx volumio[1133]: info: Enabling MyMusic plugin airplay_emulation May 19 16:52:43 smx volumio[1133]: info: Enabling plugin airplay_emulation May 19 16:52:43 smx volumio[1133]: info: Loading plugin "airplay_emulation"... May 19 16:52:43 smx volumio[1133]: info: Starting Shairport Sync May 19 16:52:43 smx volumio[1133]: info: PLUGIN START: airplay_emulation May 19 16:52:43 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 16:52:43 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 16:52:43 smx volumio[1133]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 19 16:52:43 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 16:52:43 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 16:52:43 smx volumio[1133]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 19 16:52:43 smx volumio[1133]: info: Done. May 19 16:52:43 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 19 16:52:43 smx volumio[1133]: info: Starting Shairport Sync May 19 16:52:43 smx volumio[1133]: info: Starting Shairport Sync May 19 16:52:43 smx sudo[108592]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 19 16:52:43 smx sudo[108592]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:43 smx sudo[108594]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 19 16:52:43 smx sudo[108594]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:43 smx systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 19 16:52:43 smx systemd[1]: shairport-sync.service: Deactivated successfully. May 19 16:52:43 smx systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 19 16:52:43 smx systemd[1]: shairport-sync.service: Consumed 3min 12.824s CPU time. May 19 16:52:43 smx systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 19 16:52:43 smx systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 19 16:52:43 smx sudo[108592]: pam_unix(sudo:session): session closed for user root May 19 16:52:43 smx systemd[1]: shairport-sync.service: Deactivated successfully. May 19 16:52:43 smx systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 19 16:52:43 smx volumio[1133]: info: Shairport-Sync Started May 19 16:52:43 smx volumio[1133]: Error adding Membership: Error: addMembership EINVAL May 19 16:52:43 smx systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 19 16:52:43 smx sudo[108594]: pam_unix(sudo:session): session closed for user root May 19 16:52:43 smx volumio[1133]: info: Shairport-Sync Started May 19 16:52:44 smx volumio[1133]: info: Enabling MyMusic plugin upnp_browser May 19 16:52:44 smx volumio[1133]: info: Enabling plugin upnp_browser May 19 16:52:44 smx volumio[1133]: info: Loading plugin "upnp_browser"... May 19 16:52:44 smx volumio[1133]: info: PLUGIN START: upnp_browser May 19 16:52:44 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 16:52:44 smx volumio[1133]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 19 16:52:44 smx volumio[1133]: info: [1747666364803] CoreMusicLibrary::Adding element Media Servers May 19 16:52:44 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 16:52:44 smx volumio[1133]: Cannot find translation for source TIDAL May 19 16:52:44 smx volumio[1133]: info: Done. May 19 16:52:45 smx volumio[1133]: info: Enabling MyMusic plugin bluetooth May 19 16:52:45 smx volumio[1133]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth May 19 16:52:45 smx volumio[1133]: info: Enabling plugin bluetooth May 19 16:52:45 smx volumio[1133]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: [FUNC] onStart May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service May 19 16:52:45 smx dbus-daemon[946]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.14' (uid=1000 pid=1133 comm="/usr/bin/node /volumio/index.js") May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. May 19 16:52:45 smx systemd[1]: Starting bluetooth.service - Bluetooth service... May 19 16:52:45 smx volumio[1133]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 19 16:52:45 smx kernel: Bluetooth: Core ver 2.22 May 19 16:52:45 smx kernel: NET: Registered PF_BLUETOOTH protocol family May 19 16:52:45 smx kernel: Bluetooth: HCI device and connection manager initialized May 19 16:52:45 smx kernel: Bluetooth: HCI socket layer initialized May 19 16:52:45 smx kernel: Bluetooth: L2CAP socket layer initialized May 19 16:52:45 smx kernel: Bluetooth: SCO socket layer initialized May 19 16:52:45 smx bluetoothd[108613]: Bluetooth daemon 5.72 May 19 16:52:45 smx dbus-daemon[946]: [system] Successfully activated service 'org.bluez' May 19 16:52:45 smx systemd[1]: Started bluetooth.service - Bluetooth service. May 19 16:52:45 smx bluetoothd[108613]: Starting SDP server May 19 16:52:45 smx bluetoothd[108613]: Excluding (cli) wiimote May 19 16:52:45 smx bluetoothd[108613]: Excluding (cli) sap May 19 16:52:45 smx bluetoothd[108613]: Excluding (cli) midi May 19 16:52:45 smx bluetoothd[108613]: Excluding (cli) battery May 19 16:52:45 smx kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3 May 19 16:52:45 smx kernel: Bluetooth: BNEP filters: protocol multicast May 19 16:52:45 smx kernel: Bluetooth: BNEP socket layer initialized May 19 16:52:45 smx bluetoothd[108613]: Bluetooth management interface 1.23 initialized May 19 16:52:45 smx dbus-daemon[946]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.1567' (uid=0 pid=108613 comm="/usr/libexec/bluetooth/bluetoothd --noplugin=sap,b") May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: Failed to power on adapter: May 19 16:52:45 smx systemd[1]: Starting systemd-hostnamed.service - Hostname Service... May 19 16:52:45 smx sudo[108622]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 19 16:52:45 smx sudo[108622]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:45 smx systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. May 19 16:52:45 smx sudo[108622]: pam_unix(sudo:session): session closed for user root May 19 16:52:45 smx volumio[1133]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully May 19 16:52:45 smx volumio[1133]: info: CoreCommandRouter::volumioStop May 19 16:52:45 smx volumio[1133]: info: CoreStateMachine::stop May 19 16:52:45 smx volumio[1133]: info: CoreStateMachine::serviceStop May 19 16:52:45 smx volumio[1133]: info: CoreCommandRouter::serviceStop May 19 16:52:45 smx volumio[1133]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 16:52:45 smx volumiobt[108625]: INFO [BTSTART] Ensuring Bluetooth directory exists... May 19 16:52:45 smx volumio[1133]: TypeError: Cannot read properties of undefined (reading 'then') May 19 16:52:45 smx volumio[1133]: at /myvolumio/plugins/audio_interface/bluetooth/bluetooth_real:1:12468 May 19 16:52:45 smx volumio[1133]: at ChildProcess.exithandler (node:child_process:413:7) May 19 16:52:45 smx volumio[1133]: at ChildProcess.emit (node:events:514:28) May 19 16:52:45 smx volumio[1133]: at maybeClose (node:internal/child_process:1105:16) May 19 16:52:45 smx volumio[1133]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) May 19 16:52:45 smx volumio[1133]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 16:52:45 smx sudo[108626]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth May 19 16:52:45 smx sudo[108626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:45 smx sudo[108626]: pam_unix(sudo:session): session closed for user root May 19 16:52:45 smx sudo[108631]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth May 19 16:52:45 smx sudo[108631]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 19 16:52:45 smx sudo[108631]: pam_unix(sudo:session): session closed for user root May 19 16:52:45 smx volumiobt[108642]: INFO [BTSTART] Powering on Bluetooth if needed... May 19 16:52:45 smx dbus-daemon[946]: [system] Successfully activated service 'org.freedesktop.hostname1' May 19 16:52:45 smx systemd[1]: Started systemd-hostnamed.service - Hostname Service. May 19 16:52:45 smx volumiobt[108646]: No default controller available May 19 16:52:45 smx sudo[108650]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-19 16:51' May 19 16:52:45 smx sudo[108650]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="74e551e797a3a333b0b20739125f2f8b0b974aba" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 14 16:33:49 UTC 2025" VOLUMIO_VERSION="0.066" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="aa1091f68f186e51da204c038fc19ea2"