Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 13:47:00 primo volumio[12778]: info: [1787809620005] CoreMusicLibrary::Adding element Radio Paradise Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 13:47:00 primo volumio[12778]: Cannot find translation for source Radio Paradise Aug 27 13:47:00 primo volumio[12778]: info: Volumio Calling Home Aug 27 13:47:00 primo volumio[12778]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Aug 27 13:47:00 primo volumio[12778]: (node:12778) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Aug 27 13:47:00 primo volumio[12778]: (Use `node --trace-deprecation ...` to show where the warning was created) Aug 27 13:47:00 primo volumio[12778]: info: Stopping AccessToken refresher cron for QOBUZ Aug 27 13:47:00 primo volumio[12778]: info: AccessToken refresher cron started for QOBUZ Aug 27 13:47:00 primo volumio[12778]: info: Adding TIDAL REST API Endpoints Aug 27 13:47:00 primo volumio[12778]: info: Adding QOBUZ REST API Endpoints Aug 27 13:47:00 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 27 13:47:00 primo volumio[12778]: info: Serial port opened successfully Aug 27 13:47:00 primo volumio[12778]: info: Sending serial start messages Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: Reporting MCU Network Status: 1 Aug 27 13:47:00 primo volumio[12778]: error: Upnp client error: Error: This socket has been ended by the other party Aug 27 13:47:00 primo volumio[12778]: info: Touch Event Listener Process Closed Aug 27 13:47:00 primo volumio[12778]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 27 13:47:00 primo volumio[12778]: error: Cannot start Volumio Streaming Daemon Aug 27 13:47:00 primo volumio[12778]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 27 13:47:00 primo volumio[12778]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 27 13:47:00 primo volumio[12778]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Aug 27 13:47:00 primo volumio[12778]: info: MPD Permissions set Aug 27 13:47:00 primo volumio[12778]: error: Failed to parse min max audio card capabilities, sending default vales: TypeError: Cannot read properties of undefined (reading 'split') Aug 27 13:47:00 primo sudo[13111]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Aug 27 13:47:00 primo sudo[13111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo volumio[12778]: info: MPD Permissions set Aug 27 13:47:00 primo volumio[12778]: info: Upmpdcli Daemon Started Aug 27 13:47:00 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 27 13:47:00 primo sudo[13111]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:00 primo volumio[12778]: info: Spotify config file written Aug 27 13:47:00 primo sudo[13116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 27 13:47:00 primo sudo[13116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Aug 27 13:47:00 primo systemd[1]: go-librespot-daemon.service: Deactivated successfully. Aug 27 13:47:00 primo systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:47:00 primo systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:47:00 primo sudo[13116]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:00 primo volumio[12778]: error: MPD error: The expression evaluated to a falsy value: Aug 27 13:47:00 primo volumio[12778]: assert.ok(self.idling) Aug 27 13:47:00 primo volumio[12778]: error: The expression evaluated to a falsy value: Aug 27 13:47:00 primo volumio[12778]: assert.ok(self.idling) Aug 27 13:47:00 primo go-librespot[13119]: go-librespot daemon starting... Aug 27 13:47:00 primo volumio[12778]: info: MPD running with PID13029 Aug 27 13:47:00 primo volumio[12778]: ,establishing connection Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo go-librespot[13124]: time="2026-08-27T13:47:00+08:00" level=info msg="running go-librespot 0.7.1" Aug 27 13:47:00 primo go-librespot[13124]: time="2026-08-27T13:47:00+08:00" level=debug msg="app state loaded" Aug 27 13:47:00 primo go-librespot[13124]: time="2026-08-27T13:47:00+08:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: No need to fix Spotify hosts Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Aug 27 13:47:00 primo volumio[12778]: info: Setting Device Volume Override Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 27 13:47:00 primo volumio[12778]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 80 Vol Curve; logarithmic Vol Steps: 1 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 27 13:47:00 primo volumio[12778]: info: Disabling external Volume Control Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Aug 27 13:47:00 primo volumio[12778]: info: Setting Additional System Software info: Hardware Revision: 2.2 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Aug 27 13:47:00 primo volumio[12778]: info: Setting HW Firmware info: undefined Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Aug 27 13:47:00 primo volumio[12778]: info: Setting HW Version info: 2.2 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Aug 27 13:47:00 primo volumio[12778]: info: Setting Additional System Software info: Hardware Revision: 2.2, Firmware Version: 0.4.2 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Aug 27 13:47:00 primo volumio[12778]: info: Setting HW Firmware info: 0.4.2 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Aug 27 13:47:00 primo volumio[12778]: info: Setting HW Version info: 2.2 Aug 27 13:47:00 primo volumio[12778]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Aug 27 13:47:00 primo volumio[12778]: info: MCU Signalled Headphone Mode Disabled Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Aug 27 13:47:00 primo volumio[12778]: info: Reporting Headphone State: false Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:00 primo volumio[12778]: info: Updating RAAT Signal Path Aug 27 13:47:00 primo volumio[12778]: error: Cannot write to RAAT Client: TypeError: Cannot read properties of undefined (reading 'write') Aug 27 13:47:00 primo volumio[12778]: info: MCU Signalled Sleep Mode Disabled Aug 27 13:47:00 primo volumio[12778]: info: Enabling Advanced system settings configuration Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Aug 27 13:47:00 primo volumio[12778]: info: Additional UI Settings Added for plugin music_service/inputs Aug 27 13:47:00 primo volumio[12778]: info: MCU Signalled Auto Boot Mode On Power Disabled Aug 27 13:47:00 primo volumio[12778]: error: updateQueue error: null Aug 27 13:47:00 primo sudo[13153]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Aug 27 13:47:00 primo sudo[13153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 27 13:47:00 primo volumio[12778]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Aug 27 13:47:00 primo sudo[13153]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:00 primo volumio[12778]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Aug 27 13:47:00 primo volumio[12778]: error: Serial API: Failed to decode command: MAXVOL, message: 80 Aug 27 13:47:00 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 27 13:47:00 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'. Aug 27 13:47:00 primo volumio[12778]: error: updateQueue error: null Aug 27 13:47:00 primo volumio[12778]: info: Starting Shairport Sync Aug 27 13:47:00 primo sudo[13156]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Aug 27 13:47:00 primo sudo[13156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo volumio[12778]: info: Starting Shairport Sync Aug 27 13:47:00 primo sudo[13156]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:00 primo volumio[12778]: info: Starting Shairport Sync Aug 27 13:47:00 primo sudo[13158]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 13:47:00 primo sudo[13158]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo volumio[12778]: info: Adding Inputs via Serial API Aug 27 13:47:00 primo volumio[12778]: info: Adding Advanced Audio Settings via Serial API Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Aug 27 13:47:00 primo volumio[12778]: info: Additional UI Settings Added for plugin music_service/inputs Aug 27 13:47:00 primo sudo[13163]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 13:47:00 primo sudo[13161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 27 13:47:00 primo sudo[13161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo sudo[13163]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::servicePushState Aug 27 13:47:00 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:00 primo volumio[12778]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received inputs Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::volumiosetSourceActiveno-source Aug 27 13:47:00 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 13:47:00 primo volumio[12778]: Cannot find translation for source Radio Paradise Aug 27 13:47:01 primo systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Aug 27 13:47:01 primo systemd[1]: shairport-sync.service: Deactivated successfully. Aug 27 13:47:01 primo systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 13:47:01 primo systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Aug 27 13:47:01 primo sudo[13158]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:01 primo sudo[13161]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:01 primo sudo[13163]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:01 primo volumio[12778]: info: Shairport-Sync Started Aug 27 13:47:01 primo volumio[12778]: Error adding Membership: Error: addMembership EINVAL Aug 27 13:47:01 primo volumio[12778]: info: Shairport-Sync Started Aug 27 13:47:01 primo volumio[12778]: info: Shairport-Sync Started Aug 27 13:47:01 primo systemd[1]: qobuz-connect.service: Deactivated successfully. Aug 27 13:47:01 primo systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Aug 27 13:47:01 primo systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Aug 27 13:47:01 primo sudo[13050]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:01 primo volumio[12778]: info: Executing endpoint qc_getconfig Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.384 [13182.13182] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.391 [13182.13182] INFO VolumeManager: [0xab476c78]: Setting new playback volume: 75 Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.391 [13182.13182] INFO VolumeManager: [0xab476c78]: Setting new mute state: 0 Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.391 [13182.13182] INFO AudioStreamManager: [0xab4769d0]: Setting new audio download buffer size: 1048576 Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.391 [13182.13182] INFO QobuzConnect: [0xab477540]: Client initialized! Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.391 [13182.13182] INFO SampleApp: Starting Avahi advertising, name: Primo, service name: _qobuz-connect._tcp Aug 27 13:47:01 primo volumio[12778]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Aug 27 13:47:01 primo volumio[12778]: info: QobuzConnect: QOBUZ Connect daemon connected Aug 27 13:47:01 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:01 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:01 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:01 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:01 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.411 [13182.13182] INFO LocalConfigManager: [0xab4766f8]: Starting Local Configuration server Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.411 [13182.13182] INFO SampleApp: Starting Local configuration server Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:01 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.422 [13182.13182] INFO SampleApp: Connected to UNIX socket client 0xab4618f8 Aug 27 13:47:01 primo qobuz-connect[13182]: 20260827 13:47:01.534 [13182.13182] INFO SampleApp: Playback volume changed: 75 Aug 27 13:47:01 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:01 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: TidalConnect service stoped! Aug 27 13:47:02 primo volumio[12778]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Aug 27 13:47:02 primo volumio[12778]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Aug 27 13:47:02 primo sudo[13198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Aug 27 13:47:02 primo sudo[13198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:02 primo systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Aug 27 13:47:02 primo sudo[13198]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:02 primo volumio[12778]: info: Executing endpoint tc_getconfig Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Aug 27 13:47:02 primo vtcs[13202]: STARTING TidalConnect services, version: 1.6.1 Aug 27 13:47:02 primo vtcs[13202]: STARTED TidalConnect services. Aug 27 13:47:02 primo volumio[12778]: info: Executing endpoint tc_connect Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Aug 27 13:47:02 primo volumio[12778]: info: Connecting to TidalConnect Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::servicePushState Aug 27 13:47:02 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::servicePushState Aug 27 13:47:02 primo volumio[12778]: info: CoreStateMachine::pushState Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::volumioPushState Aug 27 13:47:02 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:02 primo volumio[12778]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Aug 27 13:47:02 primo volumio[12778]: info: Initializing I2S Bus Aug 27 13:47:03 primo kernel: aml_tdm_open Aug 27 13:47:03 primo kernel: Not init audio effects Aug 27 13:47:03 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Aug 27 13:47:03 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Aug 27 13:47:03 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Aug 27 13:47:03 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Aug 27 13:47:03 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d379418, id(1), clksel(1) Aug 27 13:47:03 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Aug 27 13:47:03 primo kernel: dump_pcm_setting(ffffffc03d379418) Aug 27 13:47:03 primo kernel: pcm_mode(1) Aug 27 13:47:03 primo kernel: sysclk(11289600) Aug 27 13:47:03 primo kernel: sysclk_bclk_ratio(4) Aug 27 13:47:03 primo kernel: bclk(2822400) Aug 27 13:47:03 primo kernel: bclk_lrclk_ratio(64) Aug 27 13:47:03 primo kernel: lrclk(44100) Aug 27 13:47:03 primo kernel: tx_mask(0x3) Aug 27 13:47:03 primo kernel: rx_mask(0x3) Aug 27 13:47:03 primo kernel: slots(2) Aug 27 13:47:03 primo kernel: slot_width(32) Aug 27 13:47:03 primo kernel: lane_mask_in(0x2) Aug 27 13:47:03 primo kernel: lane_mask_out(0x1) Aug 27 13:47:03 primo kernel: lane_oe_mask_in(0x0) Aug 27 13:47:03 primo kernel: lane_oe_mask_out(0x0) Aug 27 13:47:03 primo kernel: lane_lb_mask_in(0x0) Aug 27 13:47:03 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Aug 27 13:47:03 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Aug 27 13:47:03 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Aug 27 13:47:03 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Aug 27 13:47:03 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Aug 27 13:47:03 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Aug 27 13:47:03 primo kernel: aml_tdm_prepare(), reset fddr Aug 27 13:47:03 primo kernel: spdif_a fifo ctrl, frddr:0 type:1, 16 bits, chmask 0x3, swap 0x10 Aug 27 13:47:03 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Aug 27 13:47:03 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Aug 27 13:47:03 primo kernel: tdm playback mute: 0, lane_cnt = 8 Aug 27 13:47:03 primo kernel: asoc-aml-card auge_sound: tdm playback enable Aug 27 13:47:03 primo kernel: spdif_a is set to enable Aug 27 13:47:03 primo volumio[12778]: info: go-librespot daemon successfully initialized Aug 27 13:47:04 primo kernel: asoc-aml-card auge_sound: tdm playback stop Aug 27 13:47:04 primo kernel: spdif_a is set to disable Aug 27 13:47:04 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Aug 27 13:47:04 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Aug 27 13:47:04 primo kernel: tdm playback mute: 1, lane_cnt = 8 Aug 27 13:47:04 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Aug 27 13:47:04 primo volumio[12778]: info: Successfully initialized Primo I2S Bus Aug 27 13:47:04 primo volumio[12778]: info: MRS: Getting audio outputs on start Aug 27 13:47:04 primo volumio[12778]: info: MRS: Requesting all other devices output Aug 27 13:47:04 primo volumio[12778]: error: Serial API: Failed to decode command: LEDCOLOR, message: 2 Aug 27 13:47:05 primo volumio[12778]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 27 13:47:05 primo volumio[12778]: info: TidalConnect service started! Aug 27 13:47:05 primo volumio[12778]: info: Completed starting Core Plugins Aug 27 13:47:05 primo volumio[12778]: info: ------------------------------------------- Aug 27 13:47:05 primo volumio[12778]: info: ----- MyVolumio plugins startup ---- Aug 27 13:47:05 primo volumio[12778]: info: ------------------------------------------- Aug 27 13:47:05 primo volumio[12778]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 27 13:47:06 primo volumio[12778]: info: Initializing connection to go-librespot Websocket Aug 27 13:47:09 primo volumio[12778]: info: Checking for updated MCU Firmware Aug 27 13:47:09 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 13:47:09 primo volumio[12778]: info: Firware on device is on latest version, no need to update Aug 27 13:47:25 primo volumio[12778]: error: MyVolumio Plugin failed to start in a timely fashion Aug 27 13:47:25 primo volumio[12778]: [Metrics] CommandRouter: 48s 657.98ms Aug 27 13:47:25 primo volumio[12778]: info: CoreCommandRouter::volumiosetStartupVolume Aug 27 13:47:25 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:25 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:47:25 primo volumio[12778]: info: CoreCommandRouter::Close All Modals sent Aug 27 13:47:25 primo volumio[12778]: info: CoreCommandRouter::Close All Modals sent Aug 27 13:47:25 primo volumio[12778]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Aug 27 13:47:25 primo volumio[12778]: ALSA lib confmisc.c:165:(snd_config_get_card) Cannot get card index for AUDIO Aug 27 13:47:25 primo volumio[12778]: ALSA lib ./src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback Aug 27 13:47:25 primo volumio[12778]: aplay: main:831: audio open error: No such device Aug 27 13:47:26 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 27 13:47:26 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 27 13:47:26 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Aug 27 13:47:26 primo volumio[12778]: info: Stopping RAAT Plugin Aug 27 13:47:26 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 27 13:47:26 primo sudo[13262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop raat-daemon.service Aug 27 13:47:26 primo sudo[13262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:47:26 primo sudo[13262]: pam_unix(sudo:session): session closed for user root Aug 27 13:47:26 primo volumio[12778]: info: Raat Daemon stopped successfully Aug 27 13:47:28 primo go-librespot[13124]: time="2026-08-27T13:47:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Aug 27 13:47:28 primo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 13:47:28 primo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 13:47:30 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 27 13:47:30 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:47:30 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 27 13:47:31 primo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Aug 27 13:47:31 primo systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:47:31 primo systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:47:31 primo go-librespot[13289]: go-librespot daemon starting... Aug 27 13:47:31 primo go-librespot[13290]: time="2026-08-27T13:47:31+08:00" level=info msg="running go-librespot 0.7.1" Aug 27 13:47:31 primo go-librespot[13290]: time="2026-08-27T13:47:31+08:00" level=debug msg="app state loaded" Aug 27 13:47:31 primo go-librespot[13290]: time="2026-08-27T13:47:31+08:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 13:47:32 primo volumio[12778]: info: BOOT COMPLETED Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 27 13:47:33 primo volumio[12778]: info: Not Reporting Auto name since its the default one Aug 27 13:47:33 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Aug 27 13:47:33 primo volumio[12778]: info: Configured Audio card not found, not starting RAAT Aug 27 13:47:36 primo volumio[12778]: info: RAAT: Requesting Headphone Status Aug 27 13:47:36 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Aug 27 13:47:36 primo volumio[12778]: info: MCU Signalled Headphone Mode Disabled Aug 27 13:47:36 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Aug 27 13:47:36 primo volumio[12778]: info: Reporting Headphone State: false Aug 27 13:47:36 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:36 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 27 13:47:36 primo volumio[12778]: info: Updating RAAT Signal Path Aug 27 13:47:36 primo volumio[12778]: error: Cannot write to RAAT Client: TypeError: Cannot read properties of undefined (reading 'write') Aug 27 13:47:38 primo volumio[12778]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=primo2rev2&version=4.158&uuid=c5673eaf0cdb4c24d661eedf9db7d69a" http://updates.volumio.org/downloader-v1/track-device Aug 27 13:47:38 primo volumio[12778]: % Total % Received % Xferd Average Speed Time Time Time Current Aug 27 13:47:38 primo volumio[12778]: Dload Upload Total Spent Left Speed Aug 27 13:47:38 primo volumio[12778]: [2.2K blob data] Aug 27 13:47:38 primo volumio[12778]: retrying in 5 seconds, trial 0 Aug 27 13:47:38 primo volumio[12778]: info: Volumio Calling Home Aug 27 13:47:49 primo volumio[12778]: info: Discovery: adding 43345e94-377d-4c9d-81c9-683b4e40d185 Aug 27 13:47:49 primo volumio[12778]: info: Discovery: Found device Primo Aug 27 13:47:49 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:49 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:49 primo volumio[12778]: info: MRS: Pushing multiroomSync output for this device Aug 27 13:47:49 primo volumio[12778]: info: MRS: Pushing multiroomSync output Aug 27 13:47:49 primo volumio[12778]: info: Adding audio output: Aug 27 13:47:49 primo volumio[12778]: info: Adding audio output: Aug 27 13:47:49 primo volumio[12778]: info: Discovery: this is already registered, 43345e94-377d-4c9d-81c9-683b4e40d185 Aug 27 13:47:49 primo volumio[12778]: info: Discovery: Found device Primo Aug 27 13:47:49 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:47:49 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:47:49 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Aug 27 13:47:55 primo systemd[1]: setdatetime-helper.service: Deactivated successfully. Aug 27 13:47:55 primo systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Aug 27 13:48:00 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 27 13:48:01 primo go-librespot[13290]: time="2026-08-27T13:48:01+08:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" Aug 27 13:48:01 primo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 13:48:01 primo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 13:48:02 primo volumio[12778]: info: Volumio called home Aug 27 13:48:04 primo volumio[12778]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Aug 27 13:48:04 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 27 13:48:04 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Aug 27 13:48:05 primo systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Aug 27 13:48:05 primo systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:48:05 primo systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Aug 27 13:48:05 primo go-librespot[13388]: go-librespot daemon starting... Aug 27 13:48:05 primo volumio[12778]: info: New Spotify access tokenBQAKvqUs7I... Aug 27 13:48:05 primo volumio[12778]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 27 13:48:05 primo go-librespot[13389]: time="2026-08-27T13:48:05+08:00" level=info msg="running go-librespot 0.7.1" Aug 27 13:48:05 primo go-librespot[13389]: time="2026-08-27T13:48:05+08:00" level=debug msg="app state loaded" Aug 27 13:48:05 primo go-librespot[13389]: time="2026-08-27T13:48:05+08:00" level=info msg="api server listening on 127.0.0.1:9879" Aug 27 13:48:07 primo volumio[12778]: info: Initializing connection to go-librespot Websocket Aug 27 13:48:08 primo volumio[12778]: info: MRS: Found cast device: ViewSonic PJ-5936 Aug 27 13:48:08 primo volumio[12778]: info: Adding audio output: Aug 27 13:48:08 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Aug 27 13:48:08 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Aug 27 13:48:08 primo go-librespot[13389]: time="2026-08-27T13:48:08+08:00" level=debug msg="new websocket client" Aug 27 13:48:08 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Aug 27 13:48:08 primo volumio[12778]: info: Connection to go-librespot Websocket established Aug 27 13:48:08 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Aug 27 13:48:08 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:48:08 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:48:08 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:48:08 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:48:08 primo volumio[12778]: info: MCU Signalled Playback Inactive Aug 27 13:48:09 primo volumio[12778]: SPOTIFY: User informations: {"account_id":"xhxHCm20jI","country":"TW","display_name":"鍾子傑","email":"a40701212@yahoo.com.tw","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21hn3bga6bgduipqbyaomgh5y"},"followers":{"href":null,"total":12},"href":"https://api.spotify.com/v1/users/21hn3bga6bgduipqbyaomgh5y","id":"21hn3bga6bgduipqbyaomgh5y","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=573264166106044&height=300&width=300&ext=1790401689&hash=Afu3ygJOvaufsmb3SlrIs4Qy","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=573264166106044&height=50&width=50&ext=1790401689&hash=AfvUHHadS8U8MSgEMv3-qamo","width":64}],"product":"free","type":"user","uri":"spotify:user:21hn3bga6bgduipqbyaomgh5y"} Aug 27 13:48:09 primo volumio[12778]: info: Spotify Successfully logged in Aug 27 13:48:09 primo volumio[12778]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 27 13:48:09 primo volumio[12778]: info: [1787809689769] CoreMusicLibrary::Adding element Spotify Aug 27 13:48:09 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 27 13:48:09 primo volumio[12778]: Cannot find translation for source Radio Paradise Aug 27 13:48:09 primo volumio[12778]: Cannot find translation for source Spotify Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Aug 27 13:48:10 primo volumio[12778]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Aug 27 13:48:12 primo volumio[12778]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Aug 27 13:48:12 primo volumio[12778]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Aug 27 13:48:12 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:48:12 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 27 13:48:12 primo volumio[12778]: info: Starting MyVolumio Remote Streaming Endpoints Aug 27 13:48:12 primo volumio[12778]: info: MyVolumio login type: Token Aug 27 13:48:12 primo volumio[12778]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Aug 27 13:48:12 primo volumio[12778]: error: [MyVolumio PluginManager] Could not read package.json file: Error: /myvolumio/plugins/music_service/streaming_services//package.json: ENOENT: no such file or directory, open '/myvolumio/plugins/music_service/streaming_services//package.json' Aug 27 13:48:12 primo volumio[12778]: info: Getting Spotify volume Aug 27 13:48:12 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Aug 27 13:48:12 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:48:12 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:48:12 primo volumio[12778]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Aug 27 13:48:12 primo volumio[12778]: SPOTIFY: SPOTIFY VOLUME undefined Aug 27 13:48:12 primo volumio[12778]: SPOTIFY: VOLUMIO VOLUME 33 Aug 27 13:48:12 primo volumio[12778]: info: Aligning Spotify Volume to Volumio Volume Aug 27 13:48:12 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:48:12 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:48:12 primo volumio[12778]: info: Setting Spotify Volume from Volumio: 33 Aug 27 13:48:13 primo volumio[12778]: error: MyVolumio Custom Token format not valid, refreshing it Aug 27 13:48:13 primo volumio[12778]: SPOTIFY: SETTING SPOTIFY VOLUME 33 Aug 27 13:48:13 primo volumio[12778]: info: Sending Spotify command with payload to local API: /player/volume Aug 27 13:48:19 primo volumio[12778]: info: MyVolumio login type: Token Aug 27 13:48:21 primo volumio[12778]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Aug 27 13:48:21 primo volumio[12778]: info: MyVolumio token set successfully Aug 27 13:48:21 primo volumio[12778]: info: MYVOLUMIO: Adding device Aug 27 13:48:21 primo volumio[12778]: info: MYVOLUMIO: Evaluating Server Aug 27 13:48:24 primo volumio[12778]: info: MyVolumio status changed Aug 27 13:48:24 primo volumio[12778]: info: Streaming services startup Aug 27 13:48:24 primo volumio[12778]: info: Starting Streaming Daemon Aug 27 13:48:24 primo volumio[12778]: info: Removing browser output: myVolumio user plan is not superstar Aug 27 13:48:24 primo volumio[12778]: info: Removing audio output: Aug 27 13:48:24 primo volumio[12778]: info: Stoppping Tunnel 1 Aug 27 13:48:24 primo sudo[13461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Aug 27 13:48:24 primo sudo[13461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:48:25 primo sudo[13463]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Aug 27 13:48:25 primo sudo[13463]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Aug 27 13:48:25 primo sudo[13461]: pam_unix(sudo:session): session closed for user root Aug 27 13:48:25 primo volumio[12778]: error: Cannot start Volumio Streaming Daemon Aug 27 13:48:25 primo volumio[12778]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Aug 27 13:48:25 primo volumio[12778]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo 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. Aug 27 13:48:25 primo sudo[13463]: pam_unix(sudo:session): session closed for user root Aug 27 13:48:25 primo volumio[12778]: info: Remote SSH Stopped Aug 27 13:48:27 primo volumio[12778]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 27 13:48:27 primo volumio[12778]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Aug 27 13:48:27 primo volumio[12778]: info: CoreCommandRouter::volumioGetState Aug 27 13:48:27 primo volumio[12778]: info: CorePlayQueue::getTrack 0 Aug 27 13:48:30 primo go-librespot[13389]: time="2026-08-27T13:48:30+08:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": net/http: TLS handshake timeout" Aug 27 13:48:30 primo volumio[12778]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Aug 27 13:48:30 primo volumio[12778]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 13:48:30 primo systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 27 13:48:30 primo systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Aug 27 13:48:30 primo volumio[12778]: Error: socket hang up Aug 27 13:48:30 primo volumio[12778]: at connResetException (node:internal/errors:720:14) Aug 27 13:48:30 primo volumio[12778]: at Socket.socketOnEnd (node:_http_client:519:23) Aug 27 13:48:30 primo volumio[12778]: at Socket.emit (node:events:526:35) Aug 27 13:48:30 primo volumio[12778]: at endReadableNT (node:internal/streams/readable:1376:12) Aug 27 13:48:30 primo volumio[12778]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Aug 27 13:48:30 primo volumio[12778]: code: 'ECONNRESET', Aug 27 13:48:30 primo volumio[12778]: response: undefined Aug 27 13:48:30 primo volumio[12778]: } Aug 27 13:48:30 primo volumio[12778]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 27 13:48:31 primo sudo[13493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-27 13:47' Aug 27 13:48:31 primo sudo[13493]: 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="9ccd1247f8cab3c5d64c23a96d243f6bfa34d032" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="9938d7179e3b7c4e41f3e2d60c255985cff08fee" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun May 17 17:32:08 UTC 2026" VOLUMIO_VERSION="4.158" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="43d420a3aa41c50690ebfe378df38e2b"