Nov 04 14:08:06 free ntpd[1298]: CLOCK: time stepped by 15640.430882 Nov 04 14:08:06 free ntpd[1298]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Nov 04 14:08:06 free sshd[1755]: Accepted password for volumio from 192.168.30.10 port 37188 ssh2 Nov 04 14:08:06 free sshd[1755]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Nov 04 14:08:06 free systemd-logind[1058]: New session 3 of user volumio. Nov 04 14:08:06 free systemd[1]: Started session-3.scope - Session 3 of User volumio. Nov 04 14:08:06 free sshd[1755]: pam_env(sshd:session): deprecated reading of user environment enabled Nov 04 14:08:08 free volumio[1458]: warn: [cd-plugin] cdspeedctl: device or media not ready Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Nov 04 14:08:08 free volumio[1458]: info: Adding inputs REST Endpoints Nov 04 14:08:08 free volumio[1458]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Nov 04 14:08:08 free volumio[1458]: info: Scanning Audio Inputs Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 04 14:08:08 free volumio[1458]: info: [1762265288812] CoreMusicLibrary::Adding element Loopback Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 04 14:08:08 free volumio[1458]: Cannot find translation for source FM/DAB Radio Nov 04 14:08:08 free volumio[1458]: Cannot find translation for source Loopback Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Checking against Known Cards name Nov 04 14:08:08 free volumio[1458]: info: Adding Server instance for streaming Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Nov 04 14:08:08 free volumio[1458]: error: Hi Res Audio Failed Login: Missing Login Data Nov 04 14:08:08 free volumio[1458]: info: Adding HIGHRESAUDIO REST API Endpoints Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Nov 04 14:08:08 free volumio[1458]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect Nov 04 14:08:08 free volumio[1458]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Nov 04 14:08:08 free sudo[2055]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 04 14:08:08 free volumio[1458]: info: QobuzConnect: Starting Qobuz Connect socket and service Nov 04 14:08:08 free sudo[2055]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free sudo[2062]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.832Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.835Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.835Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.835Z level=DEBUG msg="received event" component=volumio/socket event=pushBrowseSources Nov 04 14:08:08 free sudo[2062]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free volumio[1458]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Nov 04 14:08:08 free volumio[1458]: info: Stopping AccessToken refresher cron Nov 04 14:08:08 free sudo[2055]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free volumio[1458]: info: AccessToken refresher cron started Nov 04 14:08:08 free volumio[1458]: info: Stopping AccessToken refresher cron for QOBUZ Nov 04 14:08:08 free sudo[2062]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free volumio[1458]: info: AccessToken refresher cron started for QOBUZ Nov 04 14:08:08 free volumio[1458]: info: Adding TIDAL REST API Endpoints Nov 04 14:08:08 free volumio[1458]: info: Adding QOBUZ REST API Endpoints Nov 04 14:08:08 free volumio[1458]: info: MRS: Getting audio outputs on start Nov 04 14:08:08 free volumio[1458]: info: MRS: Requesting all other devices output Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.852Z level=DEBUG msg="received event" component=volumio/socket event=getMultiroomSyncOutput Nov 04 14:08:08 free volumio[1458]: info: Updating MyVolumio device info Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: Updating MyVolumio device info Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free sudo[2066]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Nov 04 14:08:08 free sudo[2066]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free volumio[1458]: info: Successfully Added MyVolumio device Nov 04 14:08:08 free volumio[1458]: info: Successfully Added MyVolumio device Nov 04 14:08:08 free volumio[1458]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.873Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 14:08:08 free volumio[1458]: info: MPD Permissions set Nov 04 14:08:08 free sudo[2070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Nov 04 14:08:08 free sudo[2070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:08 free sudo[2066]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Nov 04 14:08:08 free sudo[2070]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free volumio[1458]: info: Discovery: A device disappeared from network Nov 04 14:08:08 free volumio[1458]: info: Discovery: Device free disappeared from network Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.904Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:08 free volumio[1458]: error: updateQueue error: null Nov 04 14:08:08 free volumio[1458]: info: Discovery: A device disappeared from network Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.907Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:08 free volumio[1458]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::volumioStop Nov 04 14:08:08 free volumiobt[2083]: INFO [BTSTART] Ensuring Bluetooth directory exists... Nov 04 14:08:08 free volumio[1458]: info: CoreStateMachine::stop Nov 04 14:08:08 free volumio[1458]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 14:08:08 free volumio[1458]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Nov 04 14:08:08 free volumio[1458]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.911Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 14:08:08 free volumio[1458]: info: Starting Shairport Sync Nov 04 14:08:08 free sudo[2084]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Nov 04 14:08:08 free sudo[2084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free sudo[2084]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free sudo[2086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 04 14:08:08 free sudo[2086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free sudo[2089]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Nov 04 14:08:08 free sudo[2089]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free sudo[2089]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free volumiobt[2093]: INFO [BTSTART] Powering on Bluetooth if needed... Nov 04 14:08:08 free systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Nov 04 14:08:08 free systemd[1]: shairport-sync.service: Deactivated successfully. Nov 04 14:08:08 free systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 04 14:08:08 free systemd[1]: shairport-sync.service: Consumed 1.535s CPU time. Nov 04 14:08:08 free sudo[2098]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Nov 04 14:08:08 free sudo[2098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:08 free bluetoothd[1036]: Adv Monitor app :1.29 disconnected from D-Bus Nov 04 14:08:08 free volumiobt[2102]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Nov 04 14:08:08 free volumio[1458]: info: Executing endpoint qc_getconfig Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Nov 04 14:08:08 free qobuz-connect[2068]: 20251104 14:08:08.955 [2068.2068] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Nov 04 14:08:08 free volumiobt[2104]: [176B blob data] Nov 04 14:08:08 free volumiobt[2104]: [157B blob data] Nov 04 14:08:08 free volumiobt[2104]: [157B blob data] Nov 04 14:08:08 free volumiobt[2104]: [157B blob data] Nov 04 14:08:08 free volumiobt[2104]: [113B blob data] Nov 04 14:08:08 free volumiobt[2104]: [bluetoothctl]> discoverable on Nov 04 14:08:08 free volumiobt[2104]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Nov 04 14:08:08 free volumiobt[2104]: [bluetoothctl]> pairable on Nov 04 14:08:08 free volumio[1458]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Nov 04 14:08:08 free volumio[1458]: info: QobuzConnect: QOBUZ Connect daemon connected Nov 04 14:08:08 free volumio[1458]: info: Discovery: adding f2c0a6ec-e35c-41c3-b452-b3da66b655ab Nov 04 14:08:08 free volumio[1458]: info: Discovery: Found device Free Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:08 free systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.963Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:08 free sudo[2086]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 14:08:08 free systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Nov 04 14:08:08 free bluetoothd[1036]: Adv Monitor app :1.33 disconnected from D-Bus Nov 04 14:08:08 free systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Nov 04 14:08:08 free sudo[2098]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:08 free volumio[1458]: info: MRS: Found cast device: Google-Nest-Hub-da739cebc7bb692ba8bab67636d07159 Nov 04 14:08:08 free volumio[1458]: info: Adding audio output: Nov 04 14:08:08 free volumio[1458]: info: MRS: Found cast device: Chromecast-Ultra-b8d5e9e179c52d9e75eab34ae52a3903 Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.980Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:08 free volumiobt[2104]: [bluetoothctl]> Nov 04 14:08:08 free volumiobt[2111]: INFO [BTSTART] Registering Bluetooth agent... Nov 04 14:08:08 free volumio[1458]: info: Adding audio output: Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.982Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:08 free volumio[1458]: info: Discovery: this is already registered, f2c0a6ec-e35c-41c3-b452-b3da66b655ab Nov 04 14:08:08 free volumio[1458]: info: Discovery: Found device Free Nov 04 14:08:08 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:08 free volumio[1458]: info: MRS: Found cast device: Chromecast-5702c0fa26409e4dc282cbccce3735c4 Nov 04 14:08:08 free volumio[1458]: info: Adding audio output: Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.986Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:08 free volumio5-onboarding[1658]: time=2025-11-04T14:08:08.986Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:08 free volumio[1458]: info: Shairport-Sync Started Nov 04 14:08:08 free autossh[2112]: port set to 0, monitoring disabled Nov 04 14:08:08 free autossh[2112]: starting ssh (count 1) Nov 04 14:08:08 free autossh[2112]: ssh child pid is 2131 Nov 04 14:08:08 free volumiobt[2122]: [NEW] Media /org/bluez/hci0 Nov 04 14:08:08 free volumiobt[2122]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Nov 04 14:08:08 free volumiobt[2122]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Nov 04 14:08:08 free volumiobt[2122]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Nov 04 14:08:09 free bluetoothd[1036]: Adv Monitor app :1.37 disconnected from D-Bus Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.004 [2068.2068] INFO VolumeManager: [0x15db5c8]: Setting new playback volume: 75 Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.004 [2068.2068] INFO VolumeManager: [0x15db5c8]: Setting new mute state: 0 Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.004 [2068.2068] INFO QobuzConnect: [0x15dbf98]: Client initialized! Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.004 [2068.2068] INFO SampleApp: Starting Avahi advertising, name: Free, service name: _qobuz-connect._tcp Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.007 [2068.2068] INFO LocalConfigManager: [0x15daea8]: Starting Local Configuration server Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.008 [2068.2068] INFO SampleApp: Starting Local configuration server Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.008 [2068.2068] INFO SampleApp: Connected to UNIX socket client 0x15c5818 Nov 04 14:08:09 free volumio[1458]: info: Remote SSH Started Nov 04 14:08:09 free volumiobt[2132]: No agent is registered Nov 04 14:08:09 free volumiobt[2132]: [NEW] Media /org/bluez/hci0 Nov 04 14:08:09 free volumiobt[2132]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Nov 04 14:08:09 free volumiobt[2132]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Nov 04 14:08:09 free volumiobt[2132]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Nov 04 14:08:09 free bluetoothd[1036]: Adv Monitor app :1.40 disconnected from D-Bus Nov 04 14:08:09 free volumiobt[2135]: INFO [BTSTART] Agent registered successfully. Nov 04 14:08:09 free volumiobt[2136]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Nov 04 14:08:09 free volumiossh-tunnel[2131]: Warning: Permanently added '[eu3.myvolumio.org]:2222' (RSA) to the list of known hosts. Nov 04 14:08:09 free volumio[1458]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Nov 04 14:08:09 free volumio[1458]: info: MRS: Found cast device: Chromecast-Ultra-b8d5e9e179c52d9e75eab34ae52a3903 Nov 04 14:08:09 free volumio[1458]: info: MRS: Found cast device: Google-Nest-Hub-da739cebc7bb692ba8bab67636d07159 Nov 04 14:08:09 free volumio[1458]: info: MRS: Found cast device: Chromecast-5702c0fa26409e4dc282cbccce3735c4 Nov 04 14:08:09 free volumiossh-tunnel[2131]: Warning: remote port forwarding failed for listen port 8091 Nov 04 14:08:09 free qobuz-connect[2068]: 20251104 14:08:09.106 [2068.2068] INFO SampleApp: Playback volume changed: 75 Nov 04 14:08:09 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:09 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:09 free volumio[1458]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.dQFd7rFMkUZnTXfKxRPos4Ns44L2.4695c3b113bfacc622ef3380953058ee.state.status' Nov 04 14:08:09 free volumio[1458]: info: Successfully Updated MyVolumio device Nov 04 14:08:09 free volumio[1458]: info: Successfully Updated MyVolumio device Nov 04 14:08:09 free volumiobt[2137]: INFO:a2dp-agent:Connecting to system bus. Nov 04 14:08:09 free volumiobt[2137]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Nov 04 14:08:09 free volumiobt[2137]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Nov 04 14:08:09 free volumiobt[2137]: INFO:a2dp-agent:Registering agent. Nov 04 14:08:09 free volumiobt[2137]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Nov 04 14:08:09 free volumiobt[2137]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Nov 04 14:08:11 free volumio[1458]: info: TidalConnect service stoped! Nov 04 14:08:11 free volumio[1458]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 04 14:08:11 free volumio[1458]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 04 14:08:11 free sudo[2161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 04 14:08:11 free sudo[2161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:11 free sudo[2165]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Nov 04 14:08:11 free sudo[2165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:11 free systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Nov 04 14:08:11 free sudo[2161]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:11 free systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Nov 04 14:08:11 free systemd[1]: mpd_monitor.service: Deactivated successfully. Nov 04 14:08:11 free systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Nov 04 14:08:11 free systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Nov 04 14:08:11 free mpd_monitor.sh[2169]: MPD Monitor Service: Starting MPD Monitor Service Nov 04 14:08:11 free sudo[2165]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:11 free volumio[1458]: info: Successfully started MPD Monitor Nov 04 14:08:12 free volumio[1458]: info: Executing endpoint tc_getconfig Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Nov 04 14:08:12 free vtcs[2167]: STARTING TidalConnect services, version: 1.5.1-beta1 Nov 04 14:08:12 free vtcs[2167]: STARTED TidalConnect services. Nov 04 14:08:12 free volumio[1458]: info: Executing endpoint tc_connect Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Nov 04 14:08:12 free volumio[1458]: info: Connecting to TidalConnect Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::servicePushState Nov 04 14:08:12 free volumio[1458]: info: CoreStateMachine::pushState Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::volumioPushState Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.024Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:12 free volumio[1458]: info: MRS: Pushing multiroomSync output update for this device Nov 04 14:08:12 free volumio[1458]: info: MRS: Pushing multiroomSync output Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:12 free volumio[1458]: info: CorePlayQueue::getTrack 0 Nov 04 14:08:12 free volumio[1458]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::servicePushState Nov 04 14:08:12 free volumio[1458]: info: CoreStateMachine::pushState Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::volumioPushState Nov 04 14:08:12 free volumio[1458]: info: MRS: Pushing multiroomSync output update for this device Nov 04 14:08:12 free volumio[1458]: info: MRS: Pushing multiroomSync output Nov 04 14:08:12 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:12 free volumio[1458]: info: CorePlayQueue::getTrack 0 Nov 04 14:08:12 free volumio[1458]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.029Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.029Z level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal string into Go struct field State.volume of type int" Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiroomSyncOutput Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal string into Go struct field State.volume of type int" Nov 04 14:08:12 free volumio5-onboarding[1658]: time=2025-11-04T14:08:12.030Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiroomSyncOutput Nov 04 14:08:12 free volumio[1458]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.dQFd7rFMkUZnTXfKxRPos4Ns44L2.4695c3b113bfacc622ef3380953058ee.state.status' Nov 04 14:08:13 free systemd[1]: systemd-fsckd.service: Deactivated successfully. Nov 04 14:08:14 free volumio[1458]: info: Executing endpoint metavolumio Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 04 14:08:14 free volumio[1458]: info: TidalConnect service started! Nov 04 14:08:14 free volumio[1458]: [Metrics] CommandRouter: 24s 997.69ms Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::volumiosetStartupVolume Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:14 free volumio[1458]: info: VolumeController:: Setting startup Volume 25 Nov 04 14:08:14 free volumio[1458]: info: VolumeController::SetAlsaVolume25 Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::Close All Modals sent Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.919Z level=DEBUG msg="received event" component=volumio/socket event=closeAllModals Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::Close All Modals sent Nov 04 14:08:14 free volumio[1458]: info: CoreStateMachine::pushState Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::volumioPushState Nov 04 14:08:14 free volumio[1458]: info: MRS: Pushing multiroomSync output update for this device Nov 04 14:08:14 free volumio[1458]: info: MRS: Pushing multiroomSync output Nov 04 14:08:14 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.922Z level=DEBUG msg="received event" component=volumio/socket event=closeAllModals Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.922Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.923Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.923Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:14 free volumio5-onboarding[1658]: time=2025-11-04T14:08:14.923Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiroomSyncOutput Nov 04 14:08:15 free systemd[1]: systemd-hostnamed.service: Deactivated successfully. Nov 04 14:08:15 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 04 14:08:15 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 04 14:08:15 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 04 14:08:16 free sudo[2200]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Nov 04 14:08:16 free sudo[2200]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Nov 04 14:08:16 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 04 14:08:16 free volumio5-onboarding[1658]: time=2025-11-04T14:08:16.569Z level=DEBUG msg="received event" component=volumio/socket event=pushBackendEventsStatus Nov 04 14:08:16 free volumio[1458]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 04 14:08:16 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:16 free volumio[1458]: info: Executing endpoint metavolumio Nov 04 14:08:16 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::volumioGetBrowseSources Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 04 14:08:21 free volumio-remote-updater[1069]: Test mode enabled Nov 04 14:08:21 free volumio-remote-updater[1069]: Alpha mode disabled Nov 04 14:08:21 free volumio-remote-updater[1069]: Alpha legacy test mode disabled Nov 04 14:08:21 free volumio5-onboarding[1658]: time=2025-11-04T14:08:21.743Z level=DEBUG msg="received event" component=volumio/socket event=ClientUpdateCheck Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 04 14:08:21 free volumio[1458]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 04 14:08:21 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 04 14:08:21 free volumio[1458]: info: BOOT COMPLETED Nov 04 14:08:22 free sshd[2222]: Invalid user andrew from 192.168.30.10 port 32930 Nov 04 14:08:22 free sshd[2224]: Accepted password for volumio from 192.168.30.10 port 32932 ssh2 Nov 04 14:08:22 free sshd[2224]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Nov 04 14:08:22 free systemd-logind[1058]: New session 4 of user volumio. Nov 04 14:08:22 free systemd[1]: Started session-4.scope - Session 4 of User volumio. Nov 04 14:08:22 free sshd[2224]: pam_env(sshd:session): deprecated reading of user environment enabled Nov 04 14:08:23 free volumio5-onboarding[1658]: time=2025-11-04T14:08:23.784Z level=DEBUG msg="received event" component=volumio/socket event=pushInfinityPlayback Nov 04 14:08:32 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 04 14:08:32 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 04 14:08:35 free volumio[1458]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 04 14:08:36 free volumio[1458]: info: CALLMETHOD: music_service rtlsdr_radio saveManualFrequency [object Object] Nov 04 14:08:36 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: rtlsdr_radio , saveManualFrequency Nov 04 14:08:36 free volumio[1458]: info: [RTL-SDR Radio] Save and play manual FM: 98.8 Nov 04 14:08:36 free volumio[1458]: info: [RTL-SDR Radio] Play track: {"uri":"rtlsdr://fm/98.8","name":"FM 98.8","service":"rtlsdr_radio"} Nov 04 14:08:36 free volumio[1458]: info: [RTL-SDR Radio] Playing FM station: 98.8 MHz Nov 04 14:08:36 free volumio[1458]: info: [RTL-SDR Radio] Command: rtl_fm -f 98.8M -M wfm -s 180k -r 48k -g 50 | aplay -D volumio -f S16_LE -r 48000 -c 1 Nov 04 14:08:36 free volumio[1458]: info: CoreStateMachine::setConsumeUpdateService rtlsdr_radio Nov 04 14:08:36 free volumio[1458]: info: CoreCommandRouter::servicePushState Nov 04 14:08:36 free volumio[1458]: info: CoreStateMachine::pushState Nov 04 14:08:36 free volumio[1458]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 04 14:08:36 free volumio[1458]: info: CoreCommandRouter::volumioPushState Nov 04 14:08:36 free volumio5-onboarding[1658]: time=2025-11-04T14:08:36.685Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiRoomDevices Nov 04 14:08:36 free volumio[1458]: info: MRS: Pushing multiroomSync output update for this device Nov 04 14:08:36 free volumio[1458]: info: MRS: Pushing multiroomSync output Nov 04 14:08:36 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:36 free volumio5-onboarding[1658]: time=2025-11-04T14:08:36.691Z level=DEBUG msg="received event" component=volumio/socket event=pushState Nov 04 14:08:36 free volumio5-onboarding[1658]: time=2025-11-04T14:08:36.691Z level=DEBUG msg="received event" component=volumio/socket event=pushAudioOutputs Nov 04 14:08:36 free volumio5-onboarding[1658]: time=2025-11-04T14:08:36.691Z level=DEBUG msg="received event" component=volumio/socket event=pushMultiroomSyncOutput Nov 04 14:08:36 free volumio5-onboarding[1658]: time=2025-11-04T14:08:36.696Z level=DEBUG msg="received event" component=volumio/socket event=pushToastMessage Nov 04 14:08:36 free thd[1062]: Error reading device '/dev/input/event6' Nov 04 14:08:36 free thd[1062]: Error reading device '/dev/input/event6' Nov 04 14:08:36 free systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Nov 04 14:08:36 free kernel: r820t 16-001a: destroying instance Nov 04 14:08:36 free kernel: dvb_usb_v2: 'Realtek RTL2832U reference design:3-1' successfully deinitialized and disconnected Nov 04 14:08:45 free volumio[1458]: info: CoreCommandRouter::volumioGetState Nov 04 14:08:45 free volumio[1458]: info: CoreCommandRouter::volumioPause Nov 04 14:08:45 free volumio[1458]: info: CoreStateMachine::pause Nov 04 14:08:45 free volumio[1458]: info: CoreStateMachine::stPlaybackTimer Nov 04 14:08:45 free volumio[1458]: info: CoreStateMachine::servicePause Nov 04 14:08:45 free volumio[1458]: info: CoreCommandRouter::servicePause Nov 04 14:08:45 free volumio[1458]: info: [RTL-SDR Radio] Stopping decoder process Nov 04 14:08:45 free volumio[1458]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 14:08:45 free volumio[1458]: ReferenceError: freq is not defined Nov 04 14:08:45 free volumio[1458]: at ControllerRtlsdrRadio.stop (/data/plugins/music_service/rtlsdr_radio/index.js:299:21) Nov 04 14:08:45 free volumio[1458]: at ControllerRtlsdrRadio.pause (/data/plugins/music_service/rtlsdr_radio/index.js:318:15) Nov 04 14:08:45 free volumio[1458]: at CoreCommandRouter.servicePause (/volumio/app/index.js:387:23) Nov 04 14:08:45 free volumio[1458]: at CoreStateMachine.servicePause (/volumio/app/statemachine.js:1218:31) Nov 04 14:08:45 free volumio[1458]: at CoreStateMachine.pause (/volumio/app/statemachine.js:1201:17) Nov 04 14:08:45 free volumio[1458]: at CoreCommandRouter.volumioPause (/volumio/app/index.js:85:28) Nov 04 14:08:45 free volumio[1458]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:254:33) Nov 04 14:08:45 free volumio[1458]: at Socket.emit (node:events:514:28) Nov 04 14:08:45 free volumio[1458]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Nov 04 14:08:45 free volumio[1458]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Nov 04 14:08:45 free volumio[1458]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 04 14:08:45 free sudo[2308]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/pkill -f 'rtl_fm -f' Nov 04 14:08:45 free sudo[2308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:45 free sudo[2310]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/pkill -f 'aplay -D volumio' Nov 04 14:08:45 free sudo[2310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:45 free sudo[2310]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:45 free sudo[2308]: pam_unix(sudo:session): session closed for user root Nov 04 14:08:45 free kernel: usb 3-1: dvb_usb_v2: found a 'Realtek RTL2832U reference design' in warm state Nov 04 14:08:45 free sudo[2327]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-11-04 14:07' Nov 04 14:08:45 free sudo[2327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Nov 04 14:08:45 free kernel: usb 3-1: dvb_usb_v2: will pass the complete MPEG2 transport stream to the software demuxer Nov 04 14:08:45 free kernel: dvbdev: DVB: registering new adapter (Realtek RTL2832U reference design) Nov 04 14:08:45 free kernel: usb 3-1: media controller created Nov 04 14:08:45 free kernel: dvbdev: dvb_create_media_entity: media entity 'dvb-demux' registered. Nov 04 14:08:45 free kernel: i2c i2c-15: Added multiplexed i2c bus 16 Nov 04 14:08:45 free kernel: rtl2832 15-0010: Realtek RTL2832 successfully attached Nov 04 14:08:45 free kernel: usb 3-1: DVB: registering adapter 0 frontend 0 (Realtek RTL2832 (DVB-T))... Nov 04 14:08:45 free kernel: dvbdev: dvb_create_media_entity: media entity 'Realtek RTL2832 (DVB-T)' registered. Nov 04 14:08:45 free kernel: r820t 16-001a: creating new instance Nov 04 14:08:45 free kernel: r820t 16-001a: Rafael Micro r820t successfully identified, chip type: R820T Nov 04 14:08:46 free kernel: rtl2832_sdr rtl2832_sdr.3.auto: Registered as swradio0 Nov 04 14:08:46 free kernel: rtl2832_sdr rtl2832_sdr.3.auto: Realtek RTL2832 SDR attached Nov 04 14:08:46 free kernel: rtl2832_sdr rtl2832_sdr.3.auto: SDR API is still slightly experimental and functionality changes may follow 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="1bb44897f7ce359a55b9194fdfa5cb35d97fb06e" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="b5a4a000e056eaff366fbb6591bf2240b12246d0" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Nov 3 09:07:40 UTC 2025" VOLUMIO_VERSION="4.064" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="55f2684742b79a5937291394763da14b"