Sep 01 12:37:40 primo-plus ntpd[906]: CLOCK: time stepped by 64125.395356 Sep 01 12:37:40 primo-plus ntpd[906]: INIT: MRU 13107 entries, 13 hash bits, 32768 bytes Sep 01 12:37:40 primo-plus sudo[1436]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:41 primo-plus volumio[1196]: info: Loading plugin "upnp_browser"... Sep 01 12:37:42 primo-plus volumio[1196]: info: Starting UPNP Browser Sep 01 12:37:42 primo-plus volumio[1196]: info: Loading plugin "bluetooth"... Sep 01 12:37:43 primo-plus volumio[1196]: info: Applying required configuration parameters for plugin bluetooth Sep 01 12:37:43 primo-plus volumio[1196]: info: Applying required configuration parameters for plugin bluetooth Sep 01 12:37:43 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Sep 01 12:37:43 primo-plus volumio[1196]: info: Loading plugin "alarm-clock"... Sep 01 12:37:43 primo-plus volumio[1196]: info: Loading plugin "manifestui"... Sep 01 12:37:43 primo-plus volumio[1196]: info: Loading plugin "metavolumio"... Sep 01 12:37:46 primo-plus systemd[1]: systemd-fsckd.service: Deactivated successfully. Sep 01 12:37:46 primo-plus systemd[1]: Starting dpkg-db-backup.service - Daily dpkg database backup service... Sep 01 12:37:46 primo-plus systemd[1]: Started ntpsec-rotate-stats.service - Rotate ntpd stats. Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "airplay_emulation"... Sep 01 12:37:46 primo-plus systemd[1]: ntpsec-rotate-stats.service: Deactivated successfully. Sep 01 12:37:46 primo-plus volumio[1196]: info: Starting Shairport Sync Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "cd_controller"... Sep 01 12:37:46 primo-plus systemd[1]: dpkg-db-backup.service: Deactivated successfully. Sep 01 12:37:46 primo-plus systemd[1]: Finished dpkg-db-backup.service - Daily dpkg database backup service. Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "last_100"... Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "qobuzconnect"... Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "raat"... Sep 01 12:37:46 primo-plus volumio[1196]: info: RAAT Plugin loaded Sep 01 12:37:46 primo-plus volumio[1196]: info: Adding restartRAATSocket REST API Endpoint Sep 01 12:37:46 primo-plus volumio[1196]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat Sep 01 12:37:46 primo-plus volumio[1196]: info: Loading plugin "streaming_services"... Sep 01 12:37:46 primo-plus dhcpcd[702]: timed out Sep 01 12:37:46 primo-plus sh[692]: timed out Sep 01 12:37:47 primo-plus sh[637]: ifup: failed to bring up eth0 Sep 01 12:37:47 primo-plus systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Sep 01 12:37:47 primo-plus systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Sep 01 12:37:47 primo-plus volumio[1196]: info: Loading plugin "tidalconnect"... Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "webradio"... Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "i2s_dacs"... Sep 01 12:37:48 primo-plus volumio[1196]: info: I2S DAC not set, start Auto-detection Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "volumiodiscovery"... Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** For more information see Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 12:37:48 primo-plus volumio[1196]: *** WARNING *** For more information see Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** For more information see Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** Please fix your application to use the native API of Avahi! Sep 01 12:37:48 primo-plus node[1196]: *** WARNING *** For more information see Sep 01 12:37:48 primo-plus volumio[1196]: info: Applying required configuration parameters for plugin volumiodiscovery Sep 01 12:37:48 primo-plus volumio[1196]: info: Discovery: Started advertising with name: Primo Plus Sep 01 12:37:48 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Sep 01 12:37:48 primo-plus volumio[1196]: info: Plugin multiroom is not enabled Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "outputs"... Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "albumart"... Sep 01 12:37:48 primo-plus volumio[1196]: info: Plugin example_plugin is not enabled Sep 01 12:37:48 primo-plus volumio[1196]: info: Loading plugin "hi_res_audio"... Sep 01 12:37:48 primo-plus volumio[1822]: Forking 3 albumart workers Sep 01 12:37:48 primo-plus systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 2. Sep 01 12:37:48 primo-plus systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Sep 01 12:37:48 primo-plus systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Sep 01 12:37:48 primo-plus upmpdcli[1862]: Could not open config: /tmp/upmpdcli.conf Sep 01 12:37:48 primo-plus systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE Sep 01 12:37:48 primo-plus systemd[1]: upmpdcli.service: Failed with result 'exit-code'. Sep 01 12:37:49 primo-plus volumio[1834]: Starting albumart workers Sep 01 12:37:49 primo-plus volumio[1196]: info: Applying required configuration parameters for plugin hi_res_audio Sep 01 12:37:49 primo-plus volumio[1196]: info: Loading plugin "inputs"... Sep 01 12:37:49 primo-plus systemd[1]: systemd-hostnamed.service: Deactivated successfully. Sep 01 12:37:49 primo-plus volumio[1833]: Starting albumart workers Sep 01 12:37:50 primo-plus volumio[1832]: Starting albumart workers Sep 01 12:37:50 primo-plus volumio[1196]: info: Loading plugin "qobuz"... Sep 01 12:37:51 primo-plus volumio[1196]: info: Loading plugin "smart_inputs"... Sep 01 12:37:51 primo-plus volumio[1196]: info: Loading plugin "tidal"... Sep 01 12:37:52 primo-plus volumio[1196]: info: Loading plugin "primopluscontrol"... Sep 01 12:37:52 primo-plus volumio[1196]: info: Initializing System Ready GPIO for kernel version: 6.12.75-v8+ Sep 01 12:37:52 primo-plus volumio[1196]: info: Adding this device properties Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties Sep 01 12:37:52 primo-plus volumio[1196]: info: Setting Additional Device Volumio Properties: [object Object] Sep 01 12:37:52 primo-plus volumio[1196]: info: Loading plugin "updater_comm"... Sep 01 12:37:52 primo-plus volumio[1196]: info: Plugin mpdemulation is not enabled Sep 01 12:37:52 primo-plus volumio[1196]: info: Loading plugin "rest_api"... Sep 01 12:37:52 primo-plus volumio[1196]: info: Loading plugin "websocket"... Sep 01 12:37:52 primo-plus volumio[1196]: info: Starting Socket.io Server version 1.7.4 Sep 01 12:37:52 primo-plus volumio[1196]: info: Loading i18n strings for locale ja Sep 01 12:37:52 primo-plus volumio[1196]: Updating browse sources language Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::initPlayerControls Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 12:37:52 primo-plus volumio[1196]: Express server listening on port 3000 Sep 01 12:37:52 primo-plus volumio[1196]: [Metrics] WebUI: 19s 37.21ms Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreStateMachine::resetVolumioState Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreStateMachine::getcurrentVolume Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::volumioRetrievevolume Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:37:52 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:37:52 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:52 primo-plus sudo[1898]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 12:37:52 primo-plus sudo[1898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus sudo[1898]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus sudo[1900]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 12:37:53 primo-plus sudo[1900]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus sudo[1900]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus volumio[1196]: info: Volumio Network Manager: Network status updated: 2 Sep 01 12:37:53 primo-plus volumio[1196]: info: Reloading queue from file Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreStateMachine::setRepeat null single undefined Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:37:53 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreStateMachine::setRandom null Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:37:53 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:37:53 primo-plus volumio[1196]: info: Setting Device type: Raspberry PI Sep 01 12:37:53 primo-plus volumio[1196]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Sep 01 12:37:53 primo-plus volumio[1196]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03141 Sep 01 12:37:53 primo-plus volumio[1196]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Sep 01 12:37:53 primo-plus volumio[1196]: info: Completed loading Core Plugins Sep 01 12:37:53 primo-plus volumio[1196]: info: Preparing to generate the ALSA configuration file Sep 01 12:37:53 primo-plus sudo[1912]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Sep 01 12:37:53 primo-plus sudo[1912]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus volumio[1196]: info: Asound.conf file unchanged, so no further update is needed Sep 01 12:37:53 primo-plus volumio[1196]: info: Output device has changed, restarting MPD Sep 01 12:37:53 primo-plus sudo[1915]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 12:37:53 primo-plus sudo[1915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus volumio[1196]: info: Output device has changed, restarting Shairport Sync Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:53 primo-plus sudo[1915]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus sudo[1917]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 12:37:53 primo-plus sudo[1917]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus volumio[1196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 12:37:53 primo-plus volumio[1196]: info: ___________ START PLUGINS ___________ Sep 01 12:37:53 primo-plus volumio[1196]: info: ControllerMpd::onStart: Initializing MPD Sep 01 12:37:53 primo-plus volumio[1196]: info: Creating MPD Configuration file Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 12:37:53 primo-plus volumio[1196]: info: [1788233873349] CoreMusicLibrary::Adding element DLNAサーバー Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:53 primo-plus sudo[1925]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Sep 01 12:37:53 primo-plus sudo[1925]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus sudo[1927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 01 12:37:53 primo-plus sudo[1927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus sudo[1927]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus volumio[1196]: info: UPNP Browser: Client initialized successfully Sep 01 12:37:53 primo-plus sudo[1930]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 01 12:37:53 primo-plus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 12:37:53 primo-plus sudo[1930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:53 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: [FUNC] onStart Sep 01 12:37:53 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Sep 01 12:37:53 primo-plus systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 12:37:53 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Sep 01 12:37:53 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Sep 01 12:37:53 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding METAVOLUMIO REST API Endpoints Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:53 primo-plus volumio[1196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:53 primo-plus bluetoothd[952]: Path / reserved for Adv Monitor app :1.19 Sep 01 12:37:53 primo-plus systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server. Sep 01 12:37:53 primo-plus volumio[1196]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 01 12:37:53 primo-plus bluetoothd[952]: Adv Monitor app :1.19 disconnected from D-Bus Sep 01 12:37:53 primo-plus sudo[1925]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus systemd[1]: mpd.service: Deactivated successfully. Sep 01 12:37:53 primo-plus systemd[1]: Stopped mpd.service - Music Player Daemon. Sep 01 12:37:53 primo-plus systemd[1]: mpd.socket: Deactivated successfully. Sep 01 12:37:53 primo-plus volumio[1196]: info: Preparing CD Folders Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding CD REST API Endpoints Sep 01 12:37:53 primo-plus volumio[1196]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Sep 01 12:37:53 primo-plus volumio[1196]: info: Starting UDEV Watcher for CD Sep 01 12:37:53 primo-plus volumio[1196]: info: Detecting CD presence with UDEV Sep 01 12:37:53 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Sep 01 12:37:53 primo-plus systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Sep 01 12:37:53 primo-plus systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Sep 01 12:37:53 primo-plus systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Sep 01 12:37:53 primo-plus systemd[1]: Starting mpd.service - Music Player Daemon... Sep 01 12:37:53 primo-plus sudo[1948]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 01 12:37:53 primo-plus sudo[1948]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Sep 01 12:37:53 primo-plus sudo[1957]: /bin/chown: cannot access '/var/log/mpd.log': No such file or directory Sep 01 12:37:53 primo-plus sudo[1948]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:53 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:37:53.765+09:00 level=INFO msg="running volumio5-device-gateway" version=83ee4468+CHANGES buildDate=2026-04-15T10:25:32Z Sep 01 12:37:55 primo-plus volumio-remote-updater[762]: [2026-09-01 12:37:55] [connect] Successful connection Sep 01 12:37:55 primo-plus mpd[1958]: 2026-09-01T12:37:55 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 01 12:37:55 primo-plus systemd[1]: Started mpd.service - Music Player Daemon. Sep 01 12:37:55 primo-plus sudo[1930]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:55 primo-plus sudo[1917]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:58 primo-plus volumio[1196]: warn: [cd-plugin] cdspeedctl: device or media not ready Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 12:37:58 primo-plus volumio[1196]: info: [1788233878544] CoreMusicLibrary::Adding element Last_100 Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect Sep 01 12:37:58 primo-plus volumio[1196]: info: QobuzConnect: Starting Qobuz Connect socket and service Sep 01 12:37:58 primo-plus volumio[1196]: info: Starting RAAT Plugin Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 01 12:37:58 primo-plus volumio[1196]: info: Additional UI Settings Added for plugin music_service/raat Sep 01 12:37:58 primo-plus volumio[1196]: info: Registering DSP Elements listener and retrieving current ones Sep 01 12:37:58 primo-plus volumio[1196]: info: Additional DSP elements updated Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:58 primo-plus volumio[1196]: info: Updating RAAT Signal Path Sep 01 12:37:58 primo-plus volumio[1196]: error: Cannot write to RAAT Client: TypeError: Cannot read properties of undefined (reading 'write') Sep 01 12:37:58 primo-plus sudo[1983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Sep 01 12:37:58 primo-plus sudo[1983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:58 primo-plus volumio[1196]: info: Streaming services startup Sep 01 12:37:58 primo-plus volumio[1196]: info: Starting Streaming Daemon Sep 01 12:37:58 primo-plus sudo[1988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 12:37:58 primo-plus sudo[1988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:58 primo-plus sudo[1983]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 12:37:58 primo-plus volumio[1196]: info: [1788233878621] CoreMusicLibrary::Adding element Webradio Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:37:58 primo-plus sudo[1994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Sep 01 12:37:58 primo-plus sudo[1994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:58 primo-plus volumio[1196]: info: Initializing BBC Radios Sep 01 12:37:58 primo-plus sudo[1988]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:58 primo-plus sudo[1996]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Sep 01 12:37:58 primo-plus sudo[1996]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:37:58 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:58 primo-plus volumio[1196]: error: Hi Res Audio Failed Login: Missing Login Data Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding HIGHRESAUDIO REST API Endpoints Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Sep 01 12:37:58 primo-plus volumio[1196]: info: Initializing Serial Communication on port /dev/ttyAMA4 Sep 01 12:37:58 primo-plus systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Sep 01 12:37:58 primo-plus sudo[1994]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:58 primo-plus volumio[1196]: info: Touch Event Listener Process Starting Sep 01 12:37:58 primo-plus volumio[1196]: info: Refreshing QOBUZ token Sep 01 12:37:58 primo-plus sudo[1996]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding inputs REST Endpoints Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Sep 01 12:37:58 primo-plus volumio[1196]: info: Scanning Audio Inputs Sep 01 12:37:58 primo-plus sudo[2015]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xinput --test-xi2 --root Sep 01 12:37:58 primo-plus sudo[2015]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:58 primo-plus volumio[1196]: info: Checking against Known Cards name Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding Server instance for streaming Sep 01 12:37:58 primo-plus volumio[1196]: info: Volumio Calling Home Sep 01 12:37:58 primo-plus volumio[1196]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections Sep 01 12:37:58 primo-plus volumio[1196]: (node:1196) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Sep 01 12:37:58 primo-plus volumio[1196]: (Use `node --trace-deprecation ...` to show where the warning was created) Sep 01 12:37:58 primo-plus volumio[1196]: info: Adding TIDAL REST API Endpoints Sep 01 12:37:59 primo-plus volumio[1196]: info: Discovery: adding f166f16b-09f4-414c-82ac-ec9ee02d25cd Sep 01 12:37:59 primo-plus volumio[1196]: info: Discovery: Found device Primo Plus Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: Discovery: this is already registered, f166f16b-09f4-414c-82ac-ec9ee02d25cd Sep 01 12:37:59 primo-plus volumio[1196]: info: Discovery: Found device Primo Plus Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: Serial port opened successfully Sep 01 12:37:59 primo-plus volumio[1196]: info: Sending serial start messages Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: Reporting MCU Network Status: 2 Sep 01 12:37:59 primo-plus volumio[1196]: error: Cannot start Volumio Streaming Daemon Sep 01 12:37:59 primo-plus volumio[1196]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 12:37:59 primo-plus volumio[1196]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 12:37:59 primo-plus volumio[1196]: info: RAAT Albumart path created successfully Sep 01 12:37:59 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Sep 01 12:37:59 primo-plus volumio[1196]: info: MPD Permissions set Sep 01 12:37:59 primo-plus volumio[1196]: info: MPD Permissions set Sep 01 12:37:59 primo-plus sudo[2025]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Sep 01 12:37:59 primo-plus sudo[2025]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting Device Volume Override Sep 01 12:37:59 primo-plus volumio[1196]: info: Applying Volume Override Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 01 12:37:59 primo-plus volumio[1196]: info: Updating Volume Controller Parameters: Device: 0 Name: Analog Outputs Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 01 12:37:59 primo-plus volumio[1196]: info: Enabling external Volume Control Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Sep 01 12:37:59 primo-plus sudo[2025]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus volumiobt[2034]: INFO [BTSTART] Ensuring Bluetooth directory exists... Sep 01 12:37:59 primo-plus sudo[2035]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Sep 01 12:37:59 primo-plus sudo[2035]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2035]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus sudo[2037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Sep 01 12:37:59 primo-plus volumio[1196]: error: MPD error: The expression evaluated to a falsy value: Sep 01 12:37:59 primo-plus volumio[1196]: assert.ok(self.idling) Sep 01 12:37:59 primo-plus volumio[1196]: error: The expression evaluated to a falsy value: Sep 01 12:37:59 primo-plus volumio[1196]: assert.ok(self.idling) Sep 01 12:37:59 primo-plus sudo[2037]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2037]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus volumio[1196]: info: MPD running with PID1958 Sep 01 12:37:59 primo-plus volumio[1196]: ,establishing connection Sep 01 12:37:59 primo-plus volumiobt[2039]: INFO [BTSTART] Powering on Bluetooth if needed... Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus bluetoothd[952]: Path / reserved for Adv Monitor app :1.20 Sep 01 12:37:59 primo-plus bluetoothd[952]: Adv Monitor app :1.20 disconnected from D-Bus Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumiobt[2052]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Sep 01 12:37:59 primo-plus volumio[1196]: error: updateQueue error: null Sep 01 12:37:59 primo-plus volumiobt[2053]: [176B blob data] Sep 01 12:37:59 primo-plus volumiobt[2053]: [157B blob data] Sep 01 12:37:59 primo-plus volumiobt[2053]: [157B blob data] Sep 01 12:37:59 primo-plus volumiobt[2053]: [157B blob data] Sep 01 12:37:59 primo-plus volumiobt[2053]: [113B blob data] Sep 01 12:37:59 primo-plus volumiobt[2053]: [bluetoothctl]> discoverable on Sep 01 12:37:59 primo-plus volumiobt[2053]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended Sep 01 12:37:59 primo-plus volumiobt[2053]: [bluetoothctl]> pairable on Sep 01 12:37:59 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Sep 01 12:37:59 primo-plus volumio[1196]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Sep 01 12:37:59 primo-plus bluetoothd[952]: Path / reserved for Adv Monitor app :1.21 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting Additional System Software info: Hardware Revision: 1.1 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting HW Firmware info: undefined Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting HW Version info: 1.1 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setAdditionalSVInfo Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting Additional System Software info: Hardware Revision: 1.1, Firmware Version: 0.5.4 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setHwFwVersion Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting HW Firmware info: 0.5.4 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , setHwVersion Sep 01 12:37:59 primo-plus volumio[1196]: info: Setting HW Version info: 1.1 Sep 01 12:37:59 primo-plus volumio[1196]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff Sep 01 12:37:59 primo-plus volumio[1196]: info: MCU Signalled Headphone Mode Disabled Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Sep 01 12:37:59 primo-plus volumio[1196]: info: Reporting Headphone State: false Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:37:59 primo-plus volumio[1196]: info: Updating RAAT Signal Path Sep 01 12:37:59 primo-plus volumio[1196]: error: Cannot write to RAAT Client: TypeError: Cannot read properties of undefined (reading 'write') Sep 01 12:37:59 primo-plus volumio[1196]: info: MCU Signalled Sleep Mode Disabled Sep 01 12:37:59 primo-plus bluetoothd[952]: Adv Monitor app :1.21 disconnected from D-Bus Sep 01 12:37:59 primo-plus volumiobt[2053]: [bluetoothctl]> Sep 01 12:37:59 primo-plus volumiobt[2056]: INFO [BTSTART] Registering Bluetooth agent... Sep 01 12:37:59 primo-plus volumio[1196]: info: Enabling Advanced system settings configuration Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , addAdditionalUISections Sep 01 12:37:59 primo-plus volumio[1196]: info: Additional UI Settings Added for plugin music_service/inputs Sep 01 12:37:59 primo-plus volumio[1196]: info: MCU Signalled Auto Boot Mode On Power Disabled Sep 01 12:37:59 primo-plus volumio[1196]: info: MCU Signalled NOS Mode Disabled Sep 01 12:37:59 primo-plus volumio[1196]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Sep 01 12:37:59 primo-plus volumio[1196]: error: Serial API: Failed to decode command: MAXVOL, message: 100 Sep 01 12:37:59 primo-plus sudo[2057]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Sep 01 12:37:59 primo-plus sudo[2057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus volumiobt[2058]: [NEW] Media /org/bluez/hci0 Sep 01 12:37:59 primo-plus volumiobt[2058]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus volumiobt[2058]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus volumiobt[2058]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus bluetoothd[952]: Path / reserved for Adv Monitor app :1.22 Sep 01 12:37:59 primo-plus sudo[2057]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus bluetoothd[952]: Adv Monitor app :1.22 disconnected from D-Bus Sep 01 12:37:59 primo-plus volumio[1196]: error: updateQueue error: null Sep 01 12:37:59 primo-plus volumiobt[2060]: No agent is registered Sep 01 12:37:59 primo-plus volumiobt[2060]: [NEW] Media /org/bluez/hci0 Sep 01 12:37:59 primo-plus volumiobt[2060]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus volumiobt[2060]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus volumiobt[2060]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb Sep 01 12:37:59 primo-plus bluetoothd[952]: Adv Monitor app :1.23 disconnected from D-Bus Sep 01 12:37:59 primo-plus volumiobt[2063]: INFO [BTSTART] Agent registered successfully. Sep 01 12:37:59 primo-plus volumio[1196]: info: Starting Shairport Sync Sep 01 12:37:59 primo-plus volumiobt[2065]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Sep 01 12:37:59 primo-plus volumio[1196]: info: Starting Shairport Sync Sep 01 12:37:59 primo-plus volumio[1196]: info: Starting Shairport Sync Sep 01 12:37:59 primo-plus sudo[2064]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Sep 01 12:37:59 primo-plus sudo[2068]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 12:37:59 primo-plus sudo[2068]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2064]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 12:37:59 primo-plus sudo[2070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 01 12:37:59 primo-plus sudo[2070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:37:59 primo-plus sudo[2064]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus volumio[1196]: info: Access Token successfully retrieved Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 12:37:59 primo-plus volumio[1196]: info: [1788233879597] CoreMusicLibrary::Adding element QOBUZ Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:59 primo-plus volumio[1196]: Cannot find translation for source QOBUZ Sep 01 12:37:59 primo-plus volumio[1196]: info: Stopping AccessToken refresher cron for QOBUZ Sep 01 12:37:59 primo-plus systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Sep 01 12:37:59 primo-plus systemd[1]: shairport-sync.service: Deactivated successfully. Sep 01 12:37:59 primo-plus systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 12:37:59 primo-plus systemd[1]: shairport-sync.service: Consumed 1.774s CPU time. Sep 01 12:37:59 primo-plus systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 01 12:37:59 primo-plus sudo[2072]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus sudo[2070]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus sudo[2068]: pam_unix(sudo:session): session closed for user root Sep 01 12:37:59 primo-plus volumio[1196]: info: AccessToken refresher cron started for QOBUZ Sep 01 12:37:59 primo-plus volumio[1196]: info: Adding QOBUZ REST API Endpoints Sep 01 12:37:59 primo-plus volumio[1196]: 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: 1 Sep 01 12:37:59 primo-plus volumio[1196]: info: Shairport-Sync Started Sep 01 12:37:59 primo-plus volumio[1196]: Error adding Membership: Error: addMembership EINVAL Sep 01 12:37:59 primo-plus volumio[1196]: info: Shairport-Sync Started Sep 01 12:37:59 primo-plus volumio[1196]: info: Shairport-Sync Started Sep 01 12:37:59 primo-plus volumio[1196]: info: Volumio called home Sep 01 12:37:59 primo-plus volumio[1196]: info: Adding Inputs via Serial API Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Sep 01 12:37:59 primo-plus volumio[1196]: info: [1788233879848] CoreMusicLibrary::Adding element Inputs Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:37:59 primo-plus volumio[1196]: Cannot find translation for source QOBUZ Sep 01 12:37:59 primo-plus volumio[1196]: info: Adding Advanced Audio Settings via Serial API Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 01 12:37:59 primo-plus volumio[1196]: info: Additional UI Settings Added for plugin music_service/inputs Sep 01 12:37:59 primo-plus volumio[1196]: info: Adding Advanced Audio Settings via Serial API Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 01 12:37:59 primo-plus volumio[1196]: info: Adding Advanced Audio Settings via Serial API Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections Sep 01 12:37:59 primo-plus volumio[1196]: 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: 1 Sep 01 12:37:59 primo-plus volumio-remote-updater[762]: [2026-09-01 12:37:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1788233875 101 Sep 01 12:37:59 primo-plus volumio[1196]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 2 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:37:59 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:37:59 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:37:59 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:37:59.911+09:00 level=INFO msg="system info for cc281e6f4a7e6d6d47475ea5b83c74a1" deviceName="Primo Plus" deviceVariant=primoplus deviceModel="Volumio Primo Plus" softwareVersion=4.164 Sep 01 12:37:59 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:37:59.928+09:00 level=INFO msg="bootstrapping state" hasInternet=true Sep 01 12:37:59 primo-plus volumio[1196]: info: Executing endpoint qc_getconfig Sep 01 12:37:59 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.018 [2009.2009] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:00 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:00 primo-plus volumio[1196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::servicePushState Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received inputs Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumiosetSourceActiveno-source Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:38:00 primo-plus volumio[1196]: Cannot find translation for source QOBUZ Sep 01 12:38:00 primo-plus volumio[1196]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Sep 01 12:38:00 primo-plus volumio-remote-updater[762]: Test mode disabled Sep 01 12:38:00 primo-plus volumio-remote-updater[762]: Alpha mode disabled Sep 01 12:38:00 primo-plus volumio-remote-updater[762]: Alpha legacy test mode disabled Sep 01 12:38:00 primo-plus volumio[1196]: info: QobuzConnect: QOBUZ Connect daemon connected Sep 01 12:38:00 primo-plus volumio[1196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.169 [2009.2009] INFO VolumeManager: [0x20a3aa8]: Setting new playback volume: 75 Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.169 [2009.2009] INFO VolumeManager: [0x20a3aa8]: Setting new mute state: 0 Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.169 [2009.2009] INFO AudioStreamManager: [0x20a3800]: Setting new audio download buffer size: 1048576 Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.169 [2009.2009] INFO QobuzConnect: [0x20a4370]: Client initialized! Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.169 [2009.2009] INFO SampleApp: Starting Avahi advertising, name: Primo Plus, service name: _qobuz-connect._tcp Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.198 [2009.2009] INFO LocalConfigManager: [0x20a3528]: Starting Local Configuration server Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.198 [2009.2009] INFO SampleApp: Starting Local configuration server Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.199 [2009.2009] INFO SampleApp: Connected to UNIX socket client 0x208e8f8 Sep 01 12:38:00 primo-plus qobuz-connect[2009]: 20260901 12:38:00.199 [2009.2009] INFO SampleApp: Playback volume changed: 75 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Connecting to system D-Bus Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Connected to system D-Bus Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 bluezutils [INFO] Found adapter at: /org/bluez/hci0 Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0 Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Set DiscoverableTimeout to infinite Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Enabled Discoverable mode Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Agent registered at /local/a2dpagent Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] Agent set as default Sep 01 12:38:00 primo-plus volumiobt[2067]: 2026-09-01 12:38:00 a2dp-agent [INFO] A2DP agent running, waiting for connections... Sep 01 12:38:00 primo-plus volumio[1196]: info: MCU Signalled Playback Inactive Sep 01 12:38:00 primo-plus sudo[2101]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 12:38:00 primo-plus sudo[2101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:00 primo-plus sudo[2103]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 12:38:00 primo-plus sudo[2103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:00 primo-plus sudo[2103]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:00 primo-plus sudo[2101]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:00 primo-plus volumio[1196]: verbose: New Socket.io Connection to 192.168.1.206 from 192.168.1.84 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 12:38:00 primo-plus volumio[1196]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:00 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:00 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Sep 01 12:38:00 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:38:00.864+09:00 level=INFO msg="enabling local network discovery" Sep 01 12:38:00 primo-plus sudo[2111]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Sep 01 12:38:00 primo-plus sudo[2109]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Sep 01 12:38:00 primo-plus sudo[2109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:00 primo-plus sudo[2111]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:00 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:38:00.888+09:00 level=INFO msg="enabling BLE discovery" Sep 01 12:38:00 primo-plus sudo[2111]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:00 primo-plus sudo[2109]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:00 primo-plus volumio[1196]: verbose: New Socket.io Connection to 192.168.1.206 from 192.168.1.84 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/152.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 01 12:38:00 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:00 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:00 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:00 primo-plus volumio[1196]: info: Listing playlists Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 12:38:00 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 12:38:01 primo-plus volumio5-onboarding[1941]: time=2026-09-01T12:38:01.720+09:00 level=INFO msg="service successfully established" component=discovery/localnet Sep 01 12:38:01 primo-plus volumio[1196]: info: TidalConnect service stoped! Sep 01 12:38:01 primo-plus volumio[1196]: info: Initializing I2S Bus Sep 01 12:38:01 primo-plus volumio[1196]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Sep 01 12:38:01 primo-plus volumio[1196]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Sep 01 12:38:01 primo-plus sudo[2128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Sep 01 12:38:01 primo-plus sudo[2128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:01 primo-plus systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Sep 01 12:38:01 primo-plus sudo[2128]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:01 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:01 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 6 Sep 01 12:38:02 primo-plus volumio[1196]: info: Executing endpoint tc_getconfig Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Sep 01 12:38:02 primo-plus vtcs[2132]: STARTING TidalConnect services, version: 1.6.1 Sep 01 12:38:02 primo-plus vtcs[2132]: STARTED TidalConnect services. Sep 01 12:38:02 primo-plus volumio[1196]: info: Executing endpoint tc_connect Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Sep 01 12:38:02 primo-plus volumio[1196]: info: Connecting to TidalConnect Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::servicePushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::servicePushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreStateMachine::pushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::volumioPushState Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:02 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:02 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:02 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:02 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:03 primo-plus volumio[1196]: info: Successfully initialized I2S Bus Sep 01 12:38:03 primo-plus volumio[1196]: error: Serial API: Failed to decode command: LEDCOLOR, message: 2 Sep 01 12:38:03 primo-plus systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Sep 01 12:38:03 primo-plus systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 3. Sep 01 12:38:03 primo-plus systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD. Sep 01 12:38:03 primo-plus systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD. Sep 01 12:38:03 primo-plus sudo[1912]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:03 primo-plus volumio[1196]: info: Upmpdcli Daemon Started Sep 01 12:38:04 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:04 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:04 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:04 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:04 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:04 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:04 primo-plus volumio[1196]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: volumiokiosk-touch Engine version: 3 Transport: polling Total Clients: 7 Sep 01 12:38:04 primo-plus volumio[1196]: info: TidalConnect service started! Sep 01 12:38:04 primo-plus volumio[1196]: info: Completed starting Core Plugins Sep 01 12:38:04 primo-plus volumio[1196]: info: ------------------------------------------- Sep 01 12:38:04 primo-plus volumio[1196]: info: ----- MyVolumio plugins startup ---- Sep 01 12:38:04 primo-plus volumio[1196]: info: ------------------------------------------- Sep 01 12:38:04 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Fetching plans data.... Sep 01 12:38:05 primo-plus systemd[1]: setdatetime-helper.service: Deactivated successfully. Sep 01 12:38:05 primo-plus systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetVisibleSources Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:05 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Sep 01 12:38:05 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:05 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:05 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:05 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:05 primo-plus volumio[1196]: info: Listing playlists Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:05 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:05 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:05 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:05 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:05 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:07 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 01 12:38:07 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:07 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:07 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:07 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:07 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:07 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 01 12:38:08 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:08 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:08 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Sep 01 12:38:08 primo-plus volumio[1196]: info: Checking for updated MCU Firmware Sep 01 12:38:08 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:38:08 primo-plus volumio[1196]: info: Firware on device is on latest version, no need to update Sep 01 12:38:10 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Sep 01 12:38:13 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Sep 01 12:38:14 primo-plus volumio[1196]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Sep 01 12:38:14 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Sep 01 12:38:14 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:14 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:14 primo-plus volumio[1196]: info: Starting MyVolumio Remote Streaming Endpoints Sep 01 12:38:14 primo-plus volumio[1196]: info: MyVolumio login type: Token Sep 01 12:38:14 primo-plus volumio[1196]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Sep 01 12:38:14 primo-plus volumio[1196]: 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' Sep 01 12:38:14 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 01 12:38:15 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetQueue Sep 01 12:38:15 primo-plus volumio[1196]: info: CoreStateMachine::getQueue Sep 01 12:38:15 primo-plus volumio[1196]: info: CorePlayQueue::getQueue Sep 01 12:38:15 primo-plus volumio[1196]: error: MyVolumio Custom Token format not valid, refreshing it Sep 01 12:38:15 primo-plus volumio[1196]: info: MyVolumio login type: Token Sep 01 12:38:16 primo-plus volumio[1196]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Sep 01 12:38:16 primo-plus volumio[1196]: info: MyVolumio token set successfully Sep 01 12:38:16 primo-plus volumio[1196]: info: MYVOLUMIO: Adding device Sep 01 12:38:16 primo-plus volumio[1196]: info: MYVOLUMIO: Evaluating Server Sep 01 12:38:17 primo-plus volumio[1196]: info: MyVolumio Plan changed: premium Sep 01 12:38:17 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Sep 01 12:38:17 primo-plus volumio[1196]: info: Removing browser output: myVolumio user plan is not superstar Sep 01 12:38:17 primo-plus volumio[1196]: info: Removing audio output: Sep 01 12:38:17 primo-plus volumio[1196]: info: MYVOLUMIO: Adding device Sep 01 12:38:17 primo-plus volumio[1196]: info: MYVOLUMIO: Evaluating Server Sep 01 12:38:17 primo-plus volumio[1196]: info: Remote config written successfully Sep 01 12:38:17 primo-plus volumio[1196]: info: Starting Tunnel 1 Sep 01 12:38:17 primo-plus volumio[1196]: info: Starting Tunnel Connection Checker Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 01 12:38:17 primo-plus volumio[1196]: info: MYVolumio Device enabled Sep 01 12:38:17 primo-plus volumio[1196]: info: MyVolumio status changed Sep 01 12:38:17 primo-plus volumio[1196]: info: Streaming services startup Sep 01 12:38:17 primo-plus volumio[1196]: info: Starting Streaming Daemon Sep 01 12:38:17 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Sep 01 12:38:17 primo-plus volumio[1196]: info: Setting Geolocation for MyVolumio to as1 Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus sudo[2260]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Sep 01 12:38:17 primo-plus sudo[2260]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:17 primo-plus volumio[1196]: error: [MyVolumio PluginManager] Cache data is invalid! Sep 01 12:38:17 primo-plus sudo[2260]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:17 primo-plus volumio[1196]: error: Cannot start Volumio Streaming Daemon Sep 01 12:38:17 primo-plus volumio[1196]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Sep 01 12:38:17 primo-plus volumio[1196]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Sep 01 12:38:17 primo-plus volumio[1196]: info: handleBrowseUri took 406 milliseconds Sep 01 12:38:17 primo-plus volumio[1196]: info: Setting Geolocation for MyVolumio to as1 Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:17 primo-plus volumio[1196]: info: Preload queue cleared Sep 01 12:38:17 primo-plus volumio[1196]: info: Preload queue cleared Sep 01 12:38:17 primo-plus volumio[1196]: info: Successfully Added MyVolumio device Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin audio_interface/bluetooth is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin audio_interface/multiroom is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin miscellanea/metavolumio is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin miscellanea/manifestui is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/cd_controller is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/smart_inputs is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/hi_res_audio is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/tidal is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/qobuz is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/tidalconnect is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: [MyVolumio PluginManager] Plugin music_service/qobuzconnect is enabled for this plan, but could not be found on the local filesystem! Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Sep 01 12:38:18 primo-plus volumio[1196]: info: Successfully Added MyVolumio device Sep 01 12:38:18 primo-plus volumio[1196]: info: Updating MyVolumio device info Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: Updating MyVolumio device info Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:18 primo-plus volumio[1196]: info: Successfully Updated MyVolumio device Sep 01 12:38:19 primo-plus volumio[1196]: info: Successfully Updated MyVolumio device Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 12:38:20 primo-plus volumio[1196]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 01 12:38:20 primo-plus volumio[1196]: info: Received Get System Version Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:38:20 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:20 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:20 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:20 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:22 primo-plus sudo[2284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Sep 01 12:38:22 primo-plus sudo[2284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:22 primo-plus 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. Sep 01 12:38:22 primo-plus 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. Sep 01 12:38:22 primo-plus systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Sep 01 12:38:22 primo-plus sudo[2284]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:22 primo-plus volumio[1196]: info: Remote SSH Started Sep 01 12:38:22 primo-plus autossh[2287]: port set to 0, monitoring disabled Sep 01 12:38:22 primo-plus autossh[2287]: starting ssh (count 1) Sep 01 12:38:22 primo-plus autossh[2287]: ssh child pid is 2290 Sep 01 12:38:22 primo-plus volumio[1196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:22 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 12:38:22 primo-plus volumio[1196]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 01 12:38:22 primo-plus volumio[1196]: info: Received Get System Version Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:38:22 primo-plus volumio[1196]: info: Received Get System Info Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 01 12:38:22 primo-plus volumio[1196]: info: Discovery: Getting this device information Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:22 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:22 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 01 12:38:22 primo-plus volumiossh-tunnel[2290]: Warning: Permanently added '[as1.myvolumio.org]:2222' (RSA) to the list of known hosts. Sep 01 12:38:24 primo-plus volumio[1196]: error: MyVolumio Plugin failed to start in a timely fashion Sep 01 12:38:24 primo-plus volumio[1196]: [Metrics] CommandRouter: 50s 1.78ms Sep 01 12:38:24 primo-plus volumio[1196]: info: CoreCommandRouter::volumiosetStartupVolume Sep 01 12:38:24 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:24 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:24 primo-plus volumio[1196]: info: CoreCommandRouter::Close All Modals sent Sep 01 12:38:24 primo-plus volumio[1196]: info: CoreCommandRouter::Close All Modals sent Sep 01 12:38:25 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 01 12:38:25 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 01 12:38:26 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 01 12:38:28 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:38:28 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 01 12:38:28 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 01 12:38:28 primo-plus volumio-remote-updater[762]: Test mode disabled Sep 01 12:38:28 primo-plus volumio-remote-updater[762]: Alpha mode disabled Sep 01 12:38:28 primo-plus volumio-remote-updater[762]: Alpha legacy test mode disabled Sep 01 12:38:28 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 01 12:38:29 primo-plus volumio[1196]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 01 12:38:29 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 01 12:38:29 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 01 12:38:29 primo-plus volumio[1196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Sep 01 12:38:29 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetState Sep 01 12:38:29 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:31 primo-plus volumio[1196]: info: BOOT COMPLETED Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 01 12:38:32 primo-plus volumio[1196]: info: Not Reporting Auto name since its the default one Sep 01 12:38:32 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Sep 01 12:38:32 primo-plus sudo[2323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Sep 01 12:38:33 primo-plus sudo[2323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:33 primo-plus sudo[2323]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:33 primo-plus sudo[2325]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Sep 01 12:38:33 primo-plus sudo[2325]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 01 12:38:33 primo-plus systemd[1]: Started raat-daemon.service - RAAT DAEMON. Sep 01 12:38:33 primo-plus sudo[2325]: pam_unix(sudo:session): session closed for user root Sep 01 12:38:33 primo-plus volumio[1196]: info: Raat Daemon started successfully Sep 01 12:38:33 primo-plus volumio[1196]: info: Executing endpoint restartRAATSocket Sep 01 12:38:33 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Sep 01 12:38:33 primo-plus volumio[1196]: info: CorePlayQueue::getTrack 0 Sep 01 12:38:33 primo-plus volumio[1196]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::volumioGetBrowseSources Sep 01 12:38:34 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 01 12:38:35 primo-plus volumio[1196]: Searching plugin music_service/qobuz Sep 01 12:38:35 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Sep 01 12:38:35 primo-plus volumio[1196]: info: RAAT: Requesting Headphone Status Sep 01 12:38:35 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Sep 01 12:38:36 primo-plus volumio[1196]: info: MCU Signalled Headphone Mode Disabled Sep 01 12:38:36 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Sep 01 12:38:36 primo-plus volumio[1196]: info: Reporting Headphone State: false Sep 01 12:38:36 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:36 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 01 12:38:36 primo-plus volumio[1196]: info: Updating RAAT Signal Path Sep 01 12:38:36 primo-plus volumio[1196]: info: searchQOBUZUri took 1021 milliseconds Sep 01 12:38:36 primo-plus volumio[1196]: info: All search sources collected, pushing search results Sep 01 12:38:41 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: qobuz , handleBrowseUri Sep 01 12:38:42 primo-plus volumio[1196]: info: handleBrowseUri took 992 milliseconds Sep 01 12:38:42 primo-plus volumio[1196]: info: Preload queue cleared Sep 01 12:38:43 primo-plus volumio[1196]: info: Executing endpoint getSimilarArtists Sep 01 12:38:43 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 01 12:38:43 primo-plus volumio[1196]: info: Executing endpoint metavolumio Sep 01 12:38:43 primo-plus volumio[1196]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 01 12:38:44 primo-plus volumio[1196]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 12:38:44 primo-plus volumio[1196]: AggregateError Sep 01 12:38:44 primo-plus volumio[1196]: at internalConnectMultiple (node:net:1114:18) Sep 01 12:38:44 primo-plus volumio[1196]: at afterConnectMultiple (node:net:1667:5) { Sep 01 12:38:44 primo-plus volumio[1196]: code: 'ECONNREFUSED', Sep 01 12:38:44 primo-plus volumio[1196]: [errors]: [ Sep 01 12:38:44 primo-plus volumio[1196]: Error: connect ECONNREFUSED 158.69.209.125:443 Sep 01 12:38:44 primo-plus volumio[1196]: at createConnectionError (node:net:1634:14) Sep 01 12:38:44 primo-plus volumio[1196]: at afterConnectMultiple (node:net:1664:40) { Sep 01 12:38:44 primo-plus volumio[1196]: errno: -111, Sep 01 12:38:44 primo-plus volumio[1196]: code: 'ECONNREFUSED', Sep 01 12:38:44 primo-plus volumio[1196]: syscall: 'connect', Sep 01 12:38:44 primo-plus volumio[1196]: address: '158.69.209.125', Sep 01 12:38:44 primo-plus volumio[1196]: port: 443 Sep 01 12:38:44 primo-plus volumio[1196]: }, Sep 01 12:38:44 primo-plus volumio[1196]: Error: connect ECONNREFUSED 158.69.210.98:443 Sep 01 12:38:44 primo-plus volumio[1196]: at createConnectionError (node:net:1634:14) Sep 01 12:38:44 primo-plus volumio[1196]: at afterConnectMultiple (node:net:1664:40) { Sep 01 12:38:44 primo-plus volumio[1196]: errno: -111, Sep 01 12:38:44 primo-plus volumio[1196]: code: 'ECONNREFUSED', Sep 01 12:38:44 primo-plus volumio[1196]: syscall: 'connect', Sep 01 12:38:44 primo-plus volumio[1196]: address: '158.69.210.98', Sep 01 12:38:44 primo-plus volumio[1196]: port: 443 Sep 01 12:38:44 primo-plus volumio[1196]: } Sep 01 12:38:44 primo-plus volumio[1196]: ] Sep 01 12:38:44 primo-plus volumio[1196]: } Sep 01 12:38:44 primo-plus volumio[1196]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 01 12:38:44 primo-plus sudo[2372]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-09-01 12:37' Sep 01 12:38:44 primo-plus sudo[2372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="ceea798be624bcca033d94ae449c2a749a9724f0" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="9938d7179e3b7c4e41f3e2d60c255985cff08fee" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="primoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed May 27 09:37:15 UTC 2026" VOLUMIO_VERSION="4.164" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Primo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo Plus" VOLUMIO_HASH="c8e7083e83ff605518b1cfc23784b0e7"