-- Logs begin at Wed 2025-07-16 09:49:25 EEST, end at Wed 2025-07-16 15:45:42 EEST. -- Jul 16 15:44:02 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:02 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:07 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:07 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:12 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:12 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:17 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:17 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:22 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:22 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:27 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:27 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:32 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:32 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:37 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:37 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:42 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:42 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:47 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:47 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:52 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:52 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:44:57 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:44:57 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:02 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:02 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:07 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:07 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:11 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:11 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:11 primo volumio[3180]: verbose: New Socket.io Connection to 192.168.13.59:3000 from 192.168.13.90 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:11 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 16 15:45:11 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 16 15:45:12 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:12 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:13 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:13 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:13 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:13 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:13 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:13 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:15 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:15 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:15 primo volumio[3180]: verbose: New Socket.io Connection to 192.168.13.59:3000 from 192.168.13.90 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jul 16 15:45:15 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:15 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:15 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jul 16 15:45:15 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jul 16 15:45:15 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:15 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:16 primo sudo[27069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 16 15:45:16 primo sudo[27069]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:16 primo sudo[27069]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:16 primo sudo[27072]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 16 15:45:16 primo sudo[27072]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:16 primo sudo[27072]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:16 primo volumio[3180]: verbose: New Socket.io Connection to 192.168.13.59 from 192.168.13.90 UA: Mozilla/5.0 (Linux; Android 15; SM-S711B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/138.0.7204.67 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 16 15:45:16 primo sudo[27077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jul 16 15:45:16 primo sudo[27077]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:16 primo sudo[27077]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:16 primo sudo[27079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jul 16 15:45:16 primo sudo[27079]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 16 15:45:16 primo sudo[27079]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:16 primo volumio[3180]: verbose: New Socket.io Connection to 192.168.13.59 from 192.168.13.90 UA: Mozilla/5.0 (Linux; Android 15; SM-S711B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/138.0.7204.67 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::volumioGetVisibleSources Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:16 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 16 15:45:16 primo volumio[3180]: info: Received Get System Info Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:16 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:16 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:16 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:16 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:17 primo volumio[3180]: info: Listing playlists Jul 16 15:45:17 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jul 16 15:45:17 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 16 15:45:17 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 16 15:45:17 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:17 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 16 15:45:18 primo volumio[3180]: info: Received Get System Info Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:18 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:18 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::volumioPlay Jul 16 15:45:18 primo volumio[3180]: info: CoreStateMachine::play index undefined Jul 16 15:45:18 primo volumio[3180]: info: CoreStateMachine::setConsumeUpdateService undefined Jul 16 15:45:18 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:18 primo volumio[3180]: info: CoreStateMachine::startPlaybackTimer Jul 16 15:45:18 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::volumioGetVisibleSources Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 16 15:45:18 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jul 16 15:45:18 primo volumio[3180]: info: [1752669918830] ControllerWebradio::clearAddPlayTrack Jul 16 15:45:18 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand stop Jul 16 15:45:18 primo volumio[3180]: info: sendMpdCommand stop took 2 milliseconds Jul 16 15:45:18 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand clear Jul 16 15:45:18 primo volumio[3180]: info: Jul 16 15:45:18 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:18 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:18 primo volumio[3180]: info: sendMpdCommand clear took 4 milliseconds Jul 16 15:45:18 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand load "https://eu5.fastcast4u.com/proxy/melodia?mp=/1" Jul 16 15:45:18 primo volumio[3180]: info: Jul 16 15:45:18 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:18 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:18 primo volumio[3180]: info: Jul 16 15:45:18 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:18 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:18 primo volumio[3180]: error: updateQueue error: null Jul 16 15:45:18 primo volumio[3180]: info: ------------------------------ 11ms Jul 16 15:45:18 primo volumio[3180]: error: Upnp client error: Error: This socket has been ended by the other party Jul 16 15:45:20 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 16 15:45:20 primo volumio[3180]: info: Received Get System Info Jul 16 15:45:20 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:20 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:20 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:20 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:20 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:20 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:20 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand add "https://eu5.fastcast4u.com/proxy/melodia?mp=/1" Jul 16 15:45:20 primo volumio[3180]: error: updateQueue error: null Jul 16 15:45:20 primo volumio[3180]: info: ------------------------------ 1961ms Jul 16 15:45:20 primo volumio[3180]: info: ------------------------------ 1959ms Jul 16 15:45:20 primo volumio[3180]: info: Jul 16 15:45:20 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:20 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:20 primo volumio[3180]: info: sendMpdCommand add "https://eu5.fastcast4u.com/proxy/melodia?mp=/1" took 2 milliseconds Jul 16 15:45:20 primo volumio[3180]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 16 15:45:20 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand play Jul 16 15:45:20 primo volumio[3180]: info: Jul 16 15:45:20 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:20 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:20 primo volumio[3180]: info: Jul 16 15:45:20 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:20 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:20 primo volumio[3180]: info: ------------------------------ 12ms Jul 16 15:45:20 primo volumio[3180]: info: sendMpdCommand play took 12 milliseconds Jul 16 15:45:20 primo volumio[3180]: info: ------------------------------ 11ms Jul 16 15:45:20 primo volumio[3180]: info: ------------------------------ 9ms Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo kernel: aml_tdm_open Jul 16 15:45:21 primo kernel: Not init audio effects Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Jul 16 15:45:21 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jul 16 15:45:21 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jul 16 15:45:21 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jul 16 15:45:21 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc0508b5818, id(1), clksel(1) Jul 16 15:45:21 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Jul 16 15:45:21 primo kernel: dump_pcm_setting(ffffffc0508b5818) Jul 16 15:45:21 primo kernel: pcm_mode(1) Jul 16 15:45:21 primo kernel: sysclk(11289600) Jul 16 15:45:21 primo kernel: sysclk_bclk_ratio(4) Jul 16 15:45:21 primo kernel: bclk(2822400) Jul 16 15:45:21 primo kernel: bclk_lrclk_ratio(64) Jul 16 15:45:21 primo kernel: lrclk(44100) Jul 16 15:45:21 primo kernel: tx_mask(0x3) Jul 16 15:45:21 primo kernel: rx_mask(0x3) Jul 16 15:45:21 primo kernel: slots(2) Jul 16 15:45:21 primo kernel: slot_width(32) Jul 16 15:45:21 primo kernel: lane_mask_in(0x2) Jul 16 15:45:21 primo kernel: lane_mask_out(0x1) Jul 16 15:45:21 primo kernel: lane_oe_mask_in(0x0) Jul 16 15:45:21 primo kernel: lane_oe_mask_out(0x0) Jul 16 15:45:21 primo kernel: lane_lb_mask_in(0x0) Jul 16 15:45:21 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Jul 16 15:45:21 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Jul 16 15:45:21 primo kernel: set mclk:11289600, mpll:22579200, get mclk:11289593, mpll:22579186 Jul 16 15:45:21 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Jul 16 15:45:21 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Jul 16 15:45:21 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Jul 16 15:45:21 primo kernel: aml_tdm_prepare(), reset fddr Jul 16 15:45:21 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10 Jul 16 15:45:21 primo kernel: spdif_info: rate: 44100, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0x0, ch1_r:0x0 Jul 16 15:45:21 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Jul 16 15:45:21 primo kernel: tdm playback mute: 0, lane_cnt = 8 Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 23 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 31 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 28 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 8 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus stop Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 50ms Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 16 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 13 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 4 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 3 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 88ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 87ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 43 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 41 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 42 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 122ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 110ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 109ms Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo kernel: asoc-aml-card auge_sound: tdm playback enable Jul 16 15:45:21 primo kernel: spdif_a is set to enable Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 29ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 29 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 20ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 18 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 18ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 17 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces system playlist update Jul 16 15:45:21 primo volumio[3180]: info: Ignoring MPD Status Update Jul 16 15:45:21 primo volumio[3180]: info: Jul 16 15:45:21 primo volumio[3180]: ---------------------------- MPD announces state update: player Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::getState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand status Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 40ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 32 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 21 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 15 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 14 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 9ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 8 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 111ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 100ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 97ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 60ms Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand status took 59 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 52 milliseconds Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 50 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseState Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 132ms Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 99ms Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: sendMpdCommand playlistinfo took 76 milliseconds Jul 16 15:45:21 primo volumio[3180]: verbose: ControllerMpd::parseTrackInfo Jul 16 15:45:21 primo volumio[3180]: info: ControllerMpd::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::servicePushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: verbose: STATE SERVICE {"status":"play","position":0,"seek":855,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"1","artist":null,"album":null,"uri":"https://eu5.fastcast4u.com/proxy/melodia?mp=/1","trackType":""} Jul 16 15:45:21 primo volumio[3180]: verbose: CURRENT POSITION 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState stateService play Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::syncState currentStatus play Jul 16 15:45:21 primo volumio[3180]: info: Received an update from plugin. extracting info from payload Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CorePlayQueue::getTrack 0 Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: ------------------------------ 158ms Jul 16 15:45:21 primo volumio[3180]: info: MCU Signalled Playback Active Jul 16 15:45:21 primo volumio[3180]: info: MCU Signalled Sleep Mode Disabled Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo volumio[3180]: info: CoreStateMachine::pushState Jul 16 15:45:21 primo volumio[3180]: info: CoreCommandRouter::volumioPushState Jul 16 15:45:21 primo sudo[27098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms force on Jul 16 15:45:21 primo sudo[27098]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo volumio[3180]: info: Signalling Playback active due to playback status change Jul 16 15:45:21 primo kernel: fb: osd[0] enable: 1 (Xorg) Jul 16 15:45:21 primo kernel: fb: osd[0] enable: 1 (Xorg) Jul 16 15:45:21 primo sudo[27098]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:21 primo sudo[27104]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/xset dpms 0 0 0 Jul 16 15:45:21 primo sudo[27104]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 16 15:45:21 primo sudo[27104]: pam_unix(sudo:session): session closed for user root Jul 16 15:45:22 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:23 primo volumio[3180]: info: Executing endpoint metavolumio Jul 16 15:45:23 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 16 15:45:26 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jul 16 15:45:27 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:32 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 15:45:33 primo volumio[3180]: info: Retrieving Cloud Streaming UI Jul 16 15:45:33 primo volumio[3180]: info: Getting Tidal Cloud Configuration Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 15:45:33 primo volumio[3180]: info: Getting Qobuz Cloud Configuration Jul 16 15:45:33 primo volumio[3180]: info: Asking plugin for UI Config Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 15:45:33 primo volumio[3180]: info: Getting Spotify Cloud Configuration Jul 16 15:45:33 primo volumio[3180]: info: Asking plugin for UI Config Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 15:45:33 primo volumio[3180]: info: Saving Spotify Acccount Jul 16 15:45:33 primo volumio[3180]: info: Got it Jul 16 15:45:33 primo volumio[3180]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Jul 16 15:45:33 primo volumio[3180]: info: Got Tidal Cloud Configuration Jul 16 15:45:33 primo volumio[3180]: info: Got it Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::volumioGetBrowseSources Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::volumioGetBrowseSources Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::volumioGetBrowseSources Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 16 15:45:33 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jul 16 15:45:35 primo volumio[3180]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jul 16 15:45:35 primo volumio[3180]: info: Received Get System Version Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jul 16 15:45:35 primo volumio[3180]: info: Received Get System Info Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 16 15:45:35 primo volumio[3180]: info: Discovery: Getting this device information Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:35 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 16 15:45:36 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Jul 16 15:45:36 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Jul 16 15:45:37 primo volumio[3180]: info: CoreCommandRouter::volumioGetState Jul 16 15:45:37 primo volumio[3180]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Jul 16 15:45:37 primo volumio[3180]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L retropie.local. Jul 16 15:45:41 primo volumio[3180]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 15:45:41 primo volumio[3180]: Error: dns service error: unknown Jul 16 15:45:41 primo volumio[3180]: at MDNSService.on_resolver_done (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:19:30) Jul 16 15:45:41 primo volumio[3180]: at SocketWatcher.MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Jul 16 15:45:41 primo volumio[3180]: errorCode: -65537 Jul 16 15:45:41 primo volumio[3180]: } Jul 16 15:45:41 primo volumio[3180]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 16 15:45:42 primo sudo[27222]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-16 15:44 Jul 16 15:45:42 primo sudo[27222]: 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 05:35:39 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="edafce61cd208ac365b59b7b2fb693e3"