-- Logs begin at Sun 2025-05-11 11:05:36 CEST, end at Sun 2025-06-01 14:49:34 CEST. -- Jun 01 14:48:02 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 01 14:48:03 primo volumio[3886]: Generating RSA private key, 4096 bit long modulus (2 primes) Jun 01 14:48:04 primo volumio[3129]: error: Failed request for metavolumio API Jun 01 14:48:04 primo volumio[3129]: error: Failed request for metavolumio API Jun 01 14:48:04 primo volumio[3129]: error: Failed request for metavolumio API Jun 01 14:48:04 primo volumio[3886]: .........++++ Jun 01 14:48:11 primo volumio[3886]: ..............................................................................................++++ Jun 01 14:48:11 primo volumio[3886]: e is 65537 (0x010001) Jun 01 14:48:11 primo volumio[3886]: writing RSA key Jun 01 14:48:15 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 01 14:48:15 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:48:15 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 14:48:15 primo volumio[3129]: error: Plugin music_service qobuz failed to complete 'onStart' in a timely fashion Jun 01 14:48:15 primo volumio[3129]: info: ------------------------------------------- Jun 01 14:48:15 primo volumio[3129]: info: ----- MyVolumio plugins startup ---- Jun 01 14:48:15 primo volumio[3129]: info: ------------------------------------------- Jun 01 14:48:15 primo volumio[3129]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 01 14:48:22 primo volumio-time-update[2856]: volumio-time-update-util: Date not found in response Jun 01 14:48:22 primo volumio-time-update[2856]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 14:48:23 primo volumio[3129]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=primo2rev2&version=3.807&uuid=340b050a464c89c5b37bc529975a7e55" http://updates.volumio.org/downloader-v1/track-device Jun 01 14:48:23 primo volumio[3129]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 01 14:48:23 primo volumio[3129]: Dload Upload Total Spent Left Speed Jun 01 14:48:23 primo volumio[3129]: [2.2K blob data] Jun 01 14:48:23 primo volumio[3129]: retrying in 5 seconds, trial 0 Jun 01 14:48:23 primo volumio[3129]: info: Volumio Calling Home Jun 01 14:48:27 primo volumio-time-update[2856]: volumio-time-update-util: Fetching time from Volumio... Jun 01 14:48:35 primo volumio[3129]: error: MyVolumio Plugin failed to start in a timely fashion Jun 01 14:48:35 primo volumio[3129]: [Metrics] CommandRouter: 78s 374.83ms Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::volumiosetStartupVolume Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:48:35 primo volumio[3129]: info: VolumeController:: Setting startup Volume 80 Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::Close All Modals sent Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::Close All Modals sent Jun 01 14:48:35 primo volumio[3129]: info: CoreStateMachine::pushState Jun 01 14:48:35 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::volumioPushState Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:35 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:35 primo volumio[3129]: info: CoreStateMachine::pushState Jun 01 14:48:35 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::volumioPushState Jun 01 14:48:35 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:35 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 01 14:48:35 primo volumio[3129]: info: camilladsp stopping service pid 4077... Jun 01 14:48:35 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Jun 01 14:48:35 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Jun 01 14:48:35 primo kernel: tdm playback mute: 1, lane_cnt = 8 Jun 01 14:48:35 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Jun 01 14:48:35 primo volumio[3129]: info: camilladsp service terminated, instance 1 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 01 14:48:35 primo volumio[3129]: info: camilladsp service started and running in background, instance 1 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 01 14:48:35 primo volumio[3129]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 01 14:48:35 primo volumio[3129]: info: camilladsp spawned new process with pid 4616, instance 1, run: true Jun 01 14:48:35 primo kernel: aml_tdm_open Jun 01 14:48:35 primo kernel: Not init audio effects Jun 01 14:48:35 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Jun 01 14:48:35 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jun 01 14:48:35 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jun 01 14:48:35 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jun 01 14:48:35 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d2ab018, id(1), clksel(1) Jun 01 14:48:35 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Jun 01 14:48:35 primo kernel: dump_pcm_setting(ffffffc03d2ab018) Jun 01 14:48:35 primo kernel: pcm_mode(1) Jun 01 14:48:35 primo kernel: sysclk(11289600) Jun 01 14:48:35 primo kernel: sysclk_bclk_ratio(4) Jun 01 14:48:35 primo kernel: bclk(2822400) Jun 01 14:48:35 primo kernel: bclk_lrclk_ratio(64) Jun 01 14:48:35 primo kernel: lrclk(44100) Jun 01 14:48:35 primo kernel: tx_mask(0x3) Jun 01 14:48:35 primo kernel: rx_mask(0x3) Jun 01 14:48:35 primo kernel: slots(2) Jun 01 14:48:35 primo kernel: slot_width(32) Jun 01 14:48:35 primo kernel: lane_mask_in(0x2) Jun 01 14:48:35 primo kernel: lane_mask_out(0x1) Jun 01 14:48:35 primo kernel: lane_oe_mask_in(0x0) Jun 01 14:48:35 primo kernel: lane_oe_mask_out(0x0) Jun 01 14:48:35 primo kernel: lane_lb_mask_in(0x0) Jun 01 14:48:35 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jun 01 14:48:35 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jun 01 14:48:35 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jun 01 14:48:35 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Jun 01 14:48:35 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Jun 01 14:48:35 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Jun 01 14:48:35 primo kernel: aml_tdm_prepare(), reset fddr Jun 01 14:48:35 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Jun 01 14:48:35 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 01 14:48:35 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Jun 01 14:48:35 primo kernel: tdm playback mute: 0, lane_cnt = 8 Jun 01 14:48:35 primo kernel: asoc-aml-card auge_sound: tdm playback enable Jun 01 14:48:35 primo kernel: spdif_a is set to enable Jun 01 14:48:36 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 01 14:48:36 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 01 14:48:36 primo volumio[3129]: No protocol specified Jun 01 14:48:36 primo volumio[3129]: xcb_connection_has_error() returned true Jun 01 14:48:36 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 01 14:48:39 primo volumio[3129]: info: Discovery: adding 36db92fa-a146-44c1-a3d1-1251ae4eb27c Jun 01 14:48:39 primo volumio[3129]: info: Discovery: Found device Primo Jun 01 14:48:39 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:39 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:39 primo volumio[3129]: info: MRS: Pushing multiroomSync output for this device Jun 01 14:48:39 primo volumio[3129]: info: MRS: Pushing multiroomSync output Jun 01 14:48:39 primo volumio[3129]: info: Adding audio output: Jun 01 14:48:39 primo volumio[3129]: info: Adding audio output: Jun 01 14:48:40 primo kernel: asoc-aml-card auge_sound: tdm playback stop Jun 01 14:48:40 primo kernel: spdif_a is set to disable Jun 01 14:48:40 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Jun 01 14:48:40 primo kernel: aml_dai_tdm_hw_free(), disable mclk for TDM-B Jun 01 14:48:40 primo kernel: tdm playback mute: 1, lane_cnt = 8 Jun 01 14:48:40 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Jun 01 14:48:40 primo volumio[3129]: info: camilladsp spawned new process with pid 4630, instance 1, run: true Jun 01 14:48:41 primo kernel: aml_tdm_open Jun 01 14:48:41 primo kernel: Not init audio effects Jun 01 14:48:41 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Jun 01 14:48:41 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jun 01 14:48:41 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jun 01 14:48:41 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jun 01 14:48:41 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d2ab018, id(1), clksel(1) Jun 01 14:48:41 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Jun 01 14:48:41 primo kernel: dump_pcm_setting(ffffffc03d2ab018) Jun 01 14:48:41 primo kernel: pcm_mode(1) Jun 01 14:48:41 primo kernel: sysclk(11289600) Jun 01 14:48:41 primo kernel: sysclk_bclk_ratio(4) Jun 01 14:48:41 primo kernel: bclk(2822400) Jun 01 14:48:41 primo kernel: bclk_lrclk_ratio(64) Jun 01 14:48:41 primo kernel: lrclk(44100) Jun 01 14:48:41 primo kernel: tx_mask(0x3) Jun 01 14:48:41 primo kernel: rx_mask(0x3) Jun 01 14:48:41 primo kernel: slots(2) Jun 01 14:48:41 primo kernel: slot_width(32) Jun 01 14:48:41 primo kernel: lane_mask_in(0x2) Jun 01 14:48:41 primo kernel: lane_mask_out(0x1) Jun 01 14:48:41 primo kernel: lane_oe_mask_in(0x0) Jun 01 14:48:41 primo kernel: lane_oe_mask_out(0x0) Jun 01 14:48:41 primo kernel: lane_lb_mask_in(0x0) Jun 01 14:48:41 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jun 01 14:48:41 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jun 01 14:48:41 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jun 01 14:48:41 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Jun 01 14:48:41 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Jun 01 14:48:41 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Jun 01 14:48:41 primo kernel: aml_tdm_prepare(), reset fddr Jun 01 14:48:41 primo kernel: spdif_a fifo ctrl, frddr:0 type:3, 32 bits, chmask 0x3, swap 0x10 Jun 01 14:48:41 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jun 01 14:48:41 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Jun 01 14:48:41 primo kernel: tdm playback mute: 0, lane_cnt = 8 Jun 01 14:48:42 primo volumio[3129]: warn: QOBUZ login failed: No access token received Jun 01 14:48:42 primo volumio[3129]: info: Stopping AccessToken refresher cron for QOBUZ Jun 01 14:48:42 primo volumio[3129]: info: AccessToken refresher cron started for QOBUZ Jun 01 14:48:42 primo volumio[3129]: info: Adding QOBUZ REST API Endpoints Jun 01 14:48:42 primo volumio[3129]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Jun 01 14:48:42 primo volumio[3129]: info: BOOT COMPLETED Jun 01 14:48:42 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:48:42 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 01 14:48:42 primo volumio[3129]: info: Not Reporting Auto name since its the default one Jun 01 14:48:42 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkCurrentAudioDeviceAvailable Jun 01 14:48:42 primo volumio[3129]: No protocol specified Jun 01 14:48:42 primo volumio[3129]: xcb_connection_has_error() returned true Jun 01 14:48:43 primo sudo[4663]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed raat-daemon.service Jun 01 14:48:43 primo sudo[4663]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:43 primo sudo[4663]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:43 primo sudo[4665]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart raat-daemon.service Jun 01 14:48:43 primo sudo[4665]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:43 primo systemd[1]: Stopping RAAT DAEMON... Jun 01 14:48:43 primo systemd[1]: raat-daemon.service: Main process exited, code=killed, status=15/TERM Jun 01 14:48:43 primo systemd[1]: raat-daemon.service: Succeeded. Jun 01 14:48:43 primo systemd[1]: Stopped RAAT DAEMON. Jun 01 14:48:43 primo systemd[1]: Started RAAT DAEMON. Jun 01 14:48:43 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 01 14:48:43 primo sudo[4665]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:43 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 01 14:48:43 primo volumio[3129]: info: Raat Daemon started successfully Jun 01 14:48:43 primo volumio[3129]: info: Executing endpoint restartRAATSocket Jun 01 14:48:43 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: raat , establishDaemonConnection Jun 01 14:48:43 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:48:45 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:45 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:48:45 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:45 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:48:45 primo volumio[3129]: verbose: New Socket.io Connection to 192.168.178.22:3000 from 192.168.178.124 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:45 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 01 14:48:45 primo volumio[3129]: info: RAAT: Requesting Headphone Status Jun 01 14:48:45 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: inputs , getHeadphoneStatus Jun 01 14:48:46 primo volumio[3129]: info: MCU Signalled Headphone Mode Disabled Jun 01 14:48:46 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: raat , reportHeadphoneState Jun 01 14:48:46 primo volumio[3129]: info: Reporting Headphone State: false Jun 01 14:48:46 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:48:46 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 01 14:48:46 primo volumio[3129]: info: Updating RAAT Signal Path Jun 01 14:48:46 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:46 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:47 primo sudo[4688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 14:48:47 primo sudo[4688]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:47 primo sudo[4688]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:47 primo sudo[4690]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 14:48:47 primo sudo[4690]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:47 primo sudo[4690]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:47 primo volumio[3129]: verbose: New Socket.io Connection to 192.168.178.22 from 192.168.178.124 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 4 Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 14:48:47 primo sudo[4696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 01 14:48:47 primo sudo[4696]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:47 primo sudo[4696]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:47 primo sudo[4698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 01 14:48:47 primo sudo[4698]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:48:47 primo sudo[4698]: pam_unix(sudo:session): session closed for user root Jun 01 14:48:47 primo volumio[3129]: verbose: New Socket.io Connection to 192.168.178.22 from 192.168.178.124 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Jun 01 14:48:47 primo volumio[3129]: info: Executing endpoint metavolumio Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 01 14:48:47 primo volumio[3129]: info: Executing endpoint metavolumio Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::volumioGetVisibleSources Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:47 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::volumioGetQueue Jun 01 14:48:47 primo volumio[3129]: info: CoreStateMachine::getQueue Jun 01 14:48:47 primo volumio[3129]: info: CorePlayQueue::getQueue Jun 01 14:48:47 primo volumio[3129]: info: Listing playlists Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 01 14:48:47 primo volumio[3129]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jun 01 14:48:47 primo volumio[3129]: info: Received Get System Info Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:48:47 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:47 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:47 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 01 14:48:47 primo volumio[3129]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 01 14:48:47 primo volumio[3129]: info: FusionDsp - Bass-FusionDsp Jun 01 14:48:47 primo volumio[3129]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 14:48:49 primo volumio[3129]: info: Received Get System Info Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:48:49 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:48:49 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:49 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:48:52 primo volumio[3129]: info: CoreCommandRouter::volumioPlay Jun 01 14:48:52 primo volumio[3129]: info: CoreStateMachine::play index undefined Jun 01 14:48:52 primo volumio[3129]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 01 14:48:52 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:52 primo volumio[3129]: info: CoreStateMachine::startPlaybackTimer Jun 01 14:48:52 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:48:52 primo volumio[3129]: info: [1748782132418] ControllerQobuz::clearAddPlayTrack Jun 01 14:48:52 primo volumio[3129]: verbose: ControllerMpd::sendMpdCommand stop Jun 01 14:48:52 primo volumio[3129]: info: sendMpdCommand stop took 3 milliseconds Jun 01 14:48:52 primo volumio[3129]: verbose: ControllerMpd::sendMpdCommand clear Jun 01 14:48:52 primo volumio[3129]: info: Jun 01 14:48:52 primo volumio[3129]: ---------------------------- MPD announces system playlist update Jun 01 14:48:52 primo volumio[3129]: info: Ignoring MPD Status Update Jun 01 14:48:52 primo volumio[3129]: info: sendMpdCommand clear took 5 milliseconds Jun 01 14:48:52 primo volumio[3129]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/326477190" Jun 01 14:48:52 primo volumio[3129]: info: Jun 01 14:48:52 primo volumio[3129]: ---------------------------- MPD announces system playlist update Jun 01 14:48:52 primo volumio[3129]: info: Ignoring MPD Status Update Jun 01 14:48:52 primo volumio[3129]: info: Jun 01 14:48:52 primo volumio[3129]: ---------------------------- MPD announces system playlist update Jun 01 14:48:52 primo volumio[3129]: info: Ignoring MPD Status Update Jun 01 14:48:52 primo volumio[3129]: info: Jun 01 14:48:52 primo volumio[3129]: ---------------------------- MPD announces system playlist update Jun 01 14:48:52 primo volumio[3129]: info: Ignoring MPD Status Update Jun 01 14:48:52 primo volumio[3129]: error: updateQueue error: null Jun 01 14:48:52 primo volumio[3129]: info: ------------------------------ 18ms Jun 01 14:48:52 primo volumio[3129]: STREAMING PROXY: Handling url /?data=qobuz://song/326477190 Jun 01 14:48:52 primo volumio[3129]: info: Executing endpoint getStreamUrlqobuz Jun 01 14:48:52 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Jun 01 14:48:54 primo volumio[3129]: error: Failed request for metavolumio API Jun 01 14:48:54 primo volumio[3129]: error: Failed request for metavolumio API Jun 01 14:48:55 primo volumio-time-update[2856]: volumio-time-update-util: Date not found in response Jun 01 14:48:55 primo volumio-time-update[2856]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 14:48:57 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jun 01 14:49:00 primo volumio-time-update[2856]: volumio-time-update-util: Fetching time from Volumio... Jun 01 14:49:01 primo volumio[3129]: info: Cannot call home: Error: Command failed: /usr/bin/curl -X POST --data-binary "device=mp1&variante=primo2rev2&version=3.807&uuid=340b050a464c89c5b37bc529975a7e55" http://updates.volumio.org/downloader-v1/track-device Jun 01 14:49:01 primo volumio[3129]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 01 14:49:01 primo volumio[3129]: Dload Upload Total Spent Left Speed Jun 01 14:49:01 primo volumio[3129]: [2.2K blob data] Jun 01 14:49:01 primo volumio[3129]: retrying in 5 seconds, trial 1 Jun 01 14:49:01 primo volumio[3129]: info: Volumio Calling Home Jun 01 14:49:06 primo mpd_monitor.sh[2837]: MPD Monitor Service: MPD Appears to be inactive, restarting Jun 01 14:49:06 primo systemd[1]: Stopping Music Player Daemon... Jun 01 14:49:06 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 Jun 01 14:49:07 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jun 01 14:49:07 primo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 01 14:49:10 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:49:10 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:49:10 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:49:10 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:49:10 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:49:10 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 15 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 16 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 17 Jun 01 14:49:26 primo volumio[3129]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 18 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 19 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 20 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 21 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 22 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 23 Jun 01 14:49:26 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 24 Jun 01 14:49:27 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 25 Jun 01 14:49:27 primo volumio[3129]: info: getStreamUrl took 34623 milliseconds Jun 01 14:49:27 primo volumio[3129]: error: Could not get QOBUZ Stream URL: [object Object] Jun 01 14:49:27 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:49:27 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:49:27 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 26 Jun 01 14:49:27 primo volumio[3129]: STREAMING PROXY: Error: Failed to retrieve proper real streamUrl: {"success":false,"error":"Could not get QOBUZ Stream URL: [object Object]"} Jun 01 14:49:27 primo volumio[3129]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/326477190" Jun 01 14:49:27 primo systemd[1]: mpd.service: Succeeded. Jun 01 14:49:27 primo volumio[3129]: error: MPD error: Error: write EPIPE Jun 01 14:49:27 primo volumio[3129]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Jun 01 14:49:27 primo systemd[1]: Stopped Music Player Daemon. Jun 01 14:49:27 primo volumio[3129]: Upnp client error: Error: This socket has been ended by the other party Jun 01 14:49:27 primo systemd[1]: Starting Music Player Daemon... Jun 01 14:49:27 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jun 01 14:49:27 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 01 14:49:27 primo volumio[3129]: info: MCU Signalled Playback Inactive Jun 01 14:49:27 primo sudo[4826]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 01 14:49:27 primo sudo[4826]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:49:27 primo sudo[4826]: pam_unix(sudo:session): session closed for user root Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jun 01 14:49:28 primo volumio[3129]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jun 01 14:49:28 primo volumio-time-update[2856]: volumio-time-update-util: Date not found in response Jun 01 14:49:28 primo volumio-time-update[2856]: volumio-time-update-util: Retrying in 5 seconds... Jun 01 14:49:30 primo mpd[4835]: Jun 01 14:49 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 01 14:49:30 primo systemd[1]: Started Music Player Daemon. Jun 01 14:49:30 primo mpd_monitor.sh[2837]: MPD Monitor Service: MPD restarted due to no mpc output. Jun 01 14:49:30 primo volumio[3129]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jun 01 14:49:30 primo volumio[3129]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 01 14:49:30 primo volumio[3129]: info: Starting MyVolumio Remote Streaming Endpoints Jun 01 14:49:30 primo volumio[3129]: info: MyVolumio login type: Token Jun 01 14:49:30 primo volumio[3129]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jun 01 14:49:30 primo volumio[3129]: 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' Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 01 14:49:30 primo volumio[3129]: info: Received Get System Info Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jun 01 14:49:30 primo volumio[3129]: info: Discovery: Getting this device information Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::volumioGetState Jun 01 14:49:30 primo volumio[3129]: info: CorePlayQueue::getTrack 0 Jun 01 14:49:30 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 01 14:49:30 primo volumio[3129]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 27 Jun 01 14:49:30 primo volumio[3129]: error: MyVolumio Custom Token format not valid, refreshing it Jun 01 14:49:32 primo volumio[3129]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Jun 01 14:49:32 primo volumio[3129]: info: MyVolumio login type: Token Jun 01 14:49:32 primo volumio[3129]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jun 01 14:49:32 primo volumio[3129]: info: MyVolumio login type: Token Jun 01 14:49:33 primo volumio[3129]: info: MyVolumio token set successfully Jun 01 14:49:33 primo volumio[3129]: info: MYVOLUMIO: Adding device Jun 01 14:49:33 primo volumio[3129]: info: MYVOLUMIO: Evaluating Server Jun 01 14:49:33 primo volumio-time-update[2856]: volumio-time-update-util: Fetching time from Volumio... Jun 01 14:49:33 primo volumio-time-update[2856]: volumio-time-update-util: Setting system time to: 2025-06-01 14:49:33 Jun 01 14:49:34 primo sudo[4900]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-06-01 14:49:33 Jun 01 14:49:34 primo sudo[4900]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:49:34 primo dbus-daemon[2846]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.51' (uid=0 pid=4903 comm="timedatectl set-time 2025-06-01 14:49:33 " label="kernel") Jun 01 14:49:34 primo volumio[3129]: info: MyVolumio status changed Jun 01 14:49:34 primo volumio[3129]: info: Streaming services startup Jun 01 14:49:34 primo systemd[1]: Starting Time & Date Service... Jun 01 14:49:34 primo volumio[3129]: info: Starting Streaming Daemon Jun 01 14:49:34 primo volumio[3129]: info: Removing browser output: myVolumio user plan is not superstar Jun 01 14:49:34 primo volumio[3129]: info: Removing audio output: Jun 01 14:49:34 primo volumio[3129]: info: Stoppping Tunnel 1 Jun 01 14:49:34 primo sudo[4912]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 01 14:49:34 primo sudo[4912]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:49:34 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 01 14:49:34 primo sudo[4912]: pam_unix(sudo:session): session closed for user root Jun 01 14:49:34 primo sudo[4914]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 01 14:49:34 primo sudo[4914]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 01 14:49:34 primo volumio[3129]: error: Cannot start Volumio Streaming Daemon Jun 01 14:49:34 primo volumio[3129]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 01 14:49:34 primo volumio[3129]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 01 14:49:34 primo sudo[4914]: pam_unix(sudo:session): session closed for user root Jun 01 14:49:34 primo volumio[3129]: info: Remote SSH Stopped Jun 01 14:49:34 primo dbus-daemon[2846]: [system] Successfully activated service 'org.freedesktop.timedate1' Jun 01 14:49:34 primo systemd[1]: Started Time & Date Service. Jun 01 14:49:33 primo systemd-timedated[4906]: Changed local time to Sun Jun 1 14:49:33 2025 Jun 01 14:49:33 primo systemd[1]: Started Volumio Time Update Utility. Jun 01 14:49:33 primo volumio-time-update[2856]: volumio-time-update-util: System time updated successfully. Jun 01 14:49:33 primo sudo[4900]: pam_unix(sudo:session): session closed for user root Jun 01 14:49:33 primo systemd[1]: Reached target Multi-User System. Jun 01 14:49:33 primo systemd[1]: Reached target Graphical Interface. Jun 01 14:49:33 primo systemd[1]: Starting Update UTMP about System Runlevel Changes... Jun 01 14:49:33 primo volumio[3129]: ------------------------------------ BT MESSAGE: BT STATUS: running Jun 01 14:49:33 primo volumio[3129]: error: Failed to ping endpoint as1.myvolumio.org : unknown error Jun 01 14:49:33 primo volumio[3129]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 14:49:33 primo volumio[3129]: Error: Unable to resolve or reject the same promise twice Jun 01 14:49:33 primo volumio[3129]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43) Jun 01 14:49:33 primo volumio[3129]: at Socket. (/myvolumio/plugins/system_controller/my_volumio/my_volumio_real:1:32086) Jun 01 14:49:33 primo volumio[3129]: at Socket.emit (events.js:412:35) Jun 01 14:49:33 primo volumio[3129]: at endReadableNT (internal/streams/readable.js:1333:12) Jun 01 14:49:33 primo volumio[3129]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jun 01 14:49:33 primo volumio[3129]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 01 14:49:33 primo systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jun 01 14:49:33 primo systemd[1]: Started Update UTMP about System Runlevel Changes. Jun 01 14:49:33 primo systemd[1]: Startup finished in 13.114s (kernel) + 2min 27.512s (userspace) = 2min 40.627s. Jun 01 14:49:33 primo sudo[4930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-01 14:48 Jun 01 14:49:33 primo sudo[4930]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 30 Apr 2025 01:14:04 PM CEST" VOLUMIO_VERSION="3.807" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="e5a50903f7af6dbef467af79fe60901e"