-- Logs begin at Thu 2024-10-31 18:59:10 CET, end at Fri 2024-11-01 09:42:01 CET. -- Nov 01 09:41:07 primo sudo[31030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 09:41:07 primo sudo[31030]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:41:07 primo sudo[31030]: pam_unix(sudo:session): session closed for user root Nov 01 09:41:07 primo sudo[31034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 09:41:07 primo sudo[31034]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:41:07 primo sudo[31034]: pam_unix(sudo:session): session closed for user root Nov 01 09:41:07 primo volumio[26796]: verbose: New Socket.io Connection to 192.168.1.131 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 14; SM-A356B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Nov 01 09:41:07 primo sudo[31038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 01 09:41:07 primo sudo[31038]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:41:07 primo sudo[31038]: pam_unix(sudo:session): session closed for user root Nov 01 09:41:07 primo sudo[31042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 01 09:41:07 primo sudo[31042]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 01 09:41:07 primo sudo[31042]: pam_unix(sudo:session): session closed for user root Nov 01 09:41:07 primo volumio[26796]: verbose: New Socket.io Connection to 192.168.1.131 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 14; SM-A356B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 09:41:07 primo volumio[26796]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 01 09:41:07 primo volumio[26796]: info: Listing playlists Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Nov 01 09:41:07 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 09:41:10 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 09:41:10 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 09:41:10 primo volumio[26796]: info: Discovery: Getting this device information Nov 01 09:41:10 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:10 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 09:41:15 primo volumio[26796]: info: CoreCommandRouter::volumioSeek Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::seek Nov 01 09:41:15 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:15 primo volumio[26796]: info: TRACKBLOCK {"uri":"qobuz://song/233023789","service":"qobuz","name":"Tutti","title":"Tutti","album":"RELAX","type":"track","tracknumber":5,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/ra/n6/pt6i5oec0n6ra_600.jpg","duration":250,"explicit":false,"artist":"Calcutta","artistUri":"qobuz://artist/2645535","albumUri":"qobuz://album/pt6i5oec0n6ra","audioQuality":"","tagImage":""} Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:41:15 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:15 primo volumio[26796]: info: [1730450475170] ControllerQobuz::seek Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:15 primo volumio[26796]: info: ControllerMpd::seek Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:15 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:15 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:15 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:15 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:15 primo volumio[26796]: error: null Nov 01 09:41:15 primo volumio[26796]: info: Nov 01 09:41:15 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:15 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:15 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:15 primo volumio[26796]: info: sendMpdCommand status took 13 milliseconds Nov 01 09:41:15 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:15 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:15 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:15 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:15 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:15 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:15 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:15 primo volumio[26796]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":8000,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1568 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:15 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::syncState stateService pause Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:15 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:15 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:15 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:15 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:15 primo volumio[26796]: info: ------------------------------ 40ms Nov 01 09:41:19 primo volumio[26796]: info: CoreCommandRouter::volumioSeek Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::seek Nov 01 09:41:19 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:19 primo volumio[26796]: info: TRACKBLOCK {"uri":"qobuz://song/233023789","service":"qobuz","name":"Tutti","title":"Tutti","album":"RELAX","type":"track","tracknumber":5,"volumeNumber":1,"albumart":"https://static.qobuz.com/images/covers/ra/n6/pt6i5oec0n6ra_600.jpg","duration":250,"explicit":false,"artist":"Calcutta","artistUri":"qobuz://artist/2645535","albumUri":"qobuz://album/pt6i5oec0n6ra","audioQuality":"","tagImage":""} Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:41:19 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:19 primo volumio[26796]: info: [1730450479851] ControllerQobuz::seek Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:19 primo volumio[26796]: info: ControllerMpd::seek Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:19 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:19 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:19 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:19 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:19 primo volumio[26796]: error: null Nov 01 09:41:19 primo volumio[26796]: info: Nov 01 09:41:19 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:19 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:19 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:19 primo volumio[26796]: info: sendMpdCommand status took 10 milliseconds Nov 01 09:41:19 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:19 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:19 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:19 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:19 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:19 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:19 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:19 primo volumio[26796]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":9000,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1568 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:19 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::syncState stateService pause Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:19 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:19 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:19 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:19 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:19 primo volumio[26796]: info: ------------------------------ 30ms Nov 01 09:41:22 primo volumio[26796]: info: CoreCommandRouter::volumioPlay Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::play index undefined Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 09:41:22 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:41:22 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:22 primo volumio[26796]: info: [1730450482705] ControllerQobuz::resume Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:22 primo volumio[26796]: info: ControllerMpd::resume Nov 01 09:41:22 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand play Nov 01 09:41:22 primo volumio[26796]: info: Nov 01 09:41:22 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:22 primo volumio[26796]: info: sendMpdCommand play took 30 milliseconds Nov 01 09:41:22 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:22 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:22 primo volumio[26796]: info: sendMpdCommand status took 1 milliseconds Nov 01 09:41:22 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:22 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:22 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:22 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:22 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:22 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:22 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:22 primo volumio[26796]: verbose: STATE SERVICE {"status":"play","position":0,"seek":10234,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1612 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:22 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::syncState stateService play Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:22 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:22 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:22 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:22 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:22 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:22 primo volumio[26796]: info: ------------------------------ 21ms Nov 01 09:41:22 primo volumio[26796]: info: Signalling Playback active due to playback status change Nov 01 09:41:22 primo volumio[26796]: info: MCU Signalled Playback Active Nov 01 09:41:23 primo volumio[26796]: info: Adding qobuz://song/233023789 to favourites using generic method Nov 01 09:41:23 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: mpd , lsInfo Nov 01 09:41:23 primo volumio[26796]: error: Failed LSINFO: Error: [52@0] {lsinfo} Failed to access /song/233023789: No such file or directory Nov 01 09:41:23 primo volumio[26796]: info: Saving Cloud item favourites Nov 01 09:41:23 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem Nov 01 09:41:24 primo volumio[26796]: info: Pushing Favourites {"uri":"qobuz://song/233023789","favourite":false} Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 01 09:41:25 primo volumio[26796]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 01 09:41:25 primo volumio[26796]: info: Received Get System Version Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 01 09:41:25 primo volumio[26796]: info: Received Get System Info Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 09:41:25 primo volumio[26796]: info: Discovery: Getting this device information Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:25 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 09:41:29 primo volumio[26796]: info: CoreCommandRouter::volumioPause Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::pause Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::servicePause Nov 01 09:41:29 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:29 primo volumio[26796]: info: CoreCommandRouter::servicePause Nov 01 09:41:29 primo volumio[26796]: info: [1730450489777] ControllerQobuz::pause Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:29 primo volumio[26796]: info: ControllerMpd::pause Nov 01 09:41:29 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand pause Nov 01 09:41:29 primo volumio[26796]: info: Nov 01 09:41:29 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:29 primo volumio[26796]: info: sendMpdCommand pause took 4 milliseconds Nov 01 09:41:29 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:29 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:29 primo volumio[26796]: info: sendMpdCommand status took 1 milliseconds Nov 01 09:41:29 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:29 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:29 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:29 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:29 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:29 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:29 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:29 primo volumio[26796]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":17354,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1608 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:29 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::syncState stateService pause Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:29 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:29 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:29 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:29 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:29 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:29 primo volumio[26796]: info: ------------------------------ 19ms Nov 01 09:41:29 primo volumio[26796]: info: MCU Signalled Playback Inactive Nov 01 09:41:33 primo volumio[26796]: info: CoreCommandRouter::volumioRandom Nov 01 09:41:33 primo volumio[26796]: info: CoreCommandRouter::writePlayerControls Nov 01 09:41:33 primo volumio[26796]: info: CoreStateMachine::setRepeat true single true Nov 01 09:41:33 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:33 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:33 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:33 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:33 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:35 primo volumio[26796]: info: CoreCommandRouter::volumioRandom Nov 01 09:41:35 primo volumio[26796]: info: CoreCommandRouter::writePlayerControls Nov 01 09:41:35 primo volumio[26796]: info: CoreStateMachine::setRepeat false single false Nov 01 09:41:35 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:35 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:35 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:35 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:35 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:37 primo volumio[26796]: info: CoreCommandRouter::volumioPlay Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::play index undefined Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 09:41:37 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:41:37 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:37 primo volumio[26796]: info: [1730450497259] ControllerQobuz::resume Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:37 primo volumio[26796]: info: ControllerMpd::resume Nov 01 09:41:37 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand play Nov 01 09:41:37 primo volumio[26796]: info: Nov 01 09:41:37 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:37 primo volumio[26796]: info: sendMpdCommand play took 32 milliseconds Nov 01 09:41:37 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:37 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:37 primo volumio[26796]: info: sendMpdCommand status took 1 milliseconds Nov 01 09:41:37 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:37 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:37 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:37 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:37 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:37 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:37 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:37 primo volumio[26796]: verbose: STATE SERVICE {"status":"play","position":0,"seek":18599,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1588 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:37 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::syncState stateService play Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:37 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:37 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:37 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:37 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:37 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:37 primo volumio[26796]: info: ------------------------------ 25ms Nov 01 09:41:37 primo volumio[26796]: info: Signalling Playback active due to playback status change Nov 01 09:41:37 primo volumio[26796]: info: MCU Signalled Playback Active Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 01 09:41:40 primo volumio[26796]: info: Discovery: Getting this device information Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::volumioPause Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::pause Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::servicePause Nov 01 09:41:40 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::servicePause Nov 01 09:41:40 primo volumio[26796]: info: [1730450500705] ControllerQobuz::pause Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:40 primo volumio[26796]: info: ControllerMpd::pause Nov 01 09:41:40 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand pause Nov 01 09:41:40 primo volumio[26796]: info: Nov 01 09:41:40 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:40 primo volumio[26796]: info: sendMpdCommand pause took 2 milliseconds Nov 01 09:41:40 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:40 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:40 primo volumio[26796]: info: sendMpdCommand status took 2 milliseconds Nov 01 09:41:40 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:40 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:40 primo volumio[26796]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 01 09:41:40 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:40 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:40 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:40 primo volumio[26796]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":22097,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1652 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:40 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::syncState stateService pause Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:40 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:40 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:40 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:40 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:40 primo volumio[26796]: info: ------------------------------ 22ms Nov 01 09:41:40 primo volumio[26796]: info: MCU Signalled Playback Inactive Nov 01 09:41:41 primo volumio[26796]: info: CoreCommandRouter::volumioRandom Nov 01 09:41:41 primo volumio[26796]: info: CoreCommandRouter::writePlayerControls Nov 01 09:41:41 primo volumio[26796]: info: CoreStateMachine::setRandom true Nov 01 09:41:41 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:41 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:41 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:41 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:41 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:43 primo volumio[26796]: info: CoreCommandRouter::volumioPlay Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::play index undefined Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 01 09:41:43 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::startPlaybackTimer Nov 01 09:41:43 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:43 primo volumio[26796]: info: [1730450503220] ControllerQobuz::resume Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:43 primo volumio[26796]: info: ControllerMpd::resume Nov 01 09:41:43 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand play Nov 01 09:41:43 primo volumio[26796]: info: Nov 01 09:41:43 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:43 primo volumio[26796]: info: sendMpdCommand play took 28 milliseconds Nov 01 09:41:43 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:43 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:43 primo volumio[26796]: info: sendMpdCommand status took 1 milliseconds Nov 01 09:41:43 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:43 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:43 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:43 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:43 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:43 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:43 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:43 primo volumio[26796]: verbose: STATE SERVICE {"status":"play","position":0,"seek":23342,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1491 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:43 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::syncState stateService play Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:43 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:43 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:43 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:43 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:43 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:43 primo volumio[26796]: info: ------------------------------ 21ms Nov 01 09:41:43 primo volumio[26796]: info: Signalling Playback active due to playback status change Nov 01 09:41:43 primo volumio[26796]: info: MCU Signalled Playback Active Nov 01 09:41:45 primo volumio[26796]: info: CoreCommandRouter::volumioRandom Nov 01 09:41:45 primo volumio[26796]: info: CoreCommandRouter::writePlayerControls Nov 01 09:41:45 primo volumio[26796]: info: CoreStateMachine::setRandom false Nov 01 09:41:45 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:45 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:45 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:45 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:45 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:45 primo volumio[26796]: info: Signalling Playback active due to playback status change Nov 01 09:41:46 primo volumio[26796]: info: CoreCommandRouter::volumioPause Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::pause Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::servicePause Nov 01 09:41:46 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:46 primo volumio[26796]: info: CoreCommandRouter::servicePause Nov 01 09:41:46 primo volumio[26796]: info: [1730450506742] ControllerQobuz::pause Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 01 09:41:46 primo volumio[26796]: info: ControllerMpd::pause Nov 01 09:41:46 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand pause Nov 01 09:41:46 primo volumio[26796]: info: Nov 01 09:41:46 primo volumio[26796]: ---------------------------- MPD announces state update: player Nov 01 09:41:46 primo volumio[26796]: info: sendMpdCommand pause took 3 milliseconds Nov 01 09:41:46 primo volumio[26796]: info: ControllerMpd::getState Nov 01 09:41:46 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand status Nov 01 09:41:46 primo volumio[26796]: info: sendMpdCommand status took 1 milliseconds Nov 01 09:41:46 primo volumio[26796]: verbose: ControllerMpd::parseState Nov 01 09:41:46 primo volumio[26796]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 01 09:41:46 primo volumio[26796]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 01 09:41:46 primo volumio[26796]: verbose: ControllerMpd::parseTrackInfo Nov 01 09:41:46 primo volumio[26796]: info: ControllerMpd::pushState Nov 01 09:41:46 primo volumio[26796]: info: CoreCommandRouter::servicePushState Nov 01 09:41:46 primo volumio[26796]: info: CorePlayQueue::getTrack 1 Nov 01 09:41:46 primo volumio[26796]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26965,"duration":30,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1495 Kbps","isStreaming":false,"title":"233023789","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/233023789","trackType":"qobuz"} Nov 01 09:41:46 primo volumio[26796]: verbose: CURRENT POSITION 1 Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::syncState stateService pause Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::syncState currentStatus pause Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::pushState Nov 01 09:41:46 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 01 09:41:46 primo volumio[26796]: info: CoreCommandRouter::volumioPushState Nov 01 09:41:46 primo volumio[26796]: info: MRS: Pushing multiroomSync output update for this device Nov 01 09:41:46 primo volumio[26796]: info: MRS: Pushing multiroomSync output Nov 01 09:41:46 primo volumio[26796]: info: CoreStateMachine::stPlaybackTimer Nov 01 09:41:46 primo volumio[26796]: info: ------------------------------ 19ms Nov 01 09:41:46 primo volumio[26796]: info: MCU Signalled Playback Inactive Nov 01 09:41:57 primo volumio[26796]: verbose: New Socket.io Connection to 192.168.1.131 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 14; SM-A356B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 01 09:41:57 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:57 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 09:41:57 primo volumio[26796]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 01 09:41:57 primo volumio[26796]: info: Listing playlists Nov 01 09:41:59 primo volumio[26796]: verbose: New Socket.io Connection to 192.168.1.131 from 192.168.1.116 UA: Mozilla/5.0 (Linux; Android 14; SM-A356B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/130.0.6723.60 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 01 09:41:59 primo volumio[26796]: info: CoreCommandRouter::volumioGetState Nov 01 09:41:59 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 01 09:41:59 primo volumio[26796]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 01 09:41:59 primo volumio[26796]: info: Listing playlists Nov 01 09:42:00 primo volumio[26796]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Nov 01 09:42:00 primo volumio[26796]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Nov 01 09:42:00 primo volumio[26796]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 09:42:00 primo volumio[26796]: TypeError: Cannot read property 'then' of undefined Nov 01 09:42:00 primo volumio[26796]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Nov 01 09:42:00 primo volumio[26796]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30) Nov 01 09:42:00 primo volumio[26796]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1442:26) Nov 01 09:42:00 primo volumio[26796]: at Socket.emit (events.js:400:28) Nov 01 09:42:00 primo volumio[26796]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 01 09:42:00 primo volumio[26796]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Nov 01 09:42:00 primo volumio[26796]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 01 09:42:01 primo sudo[31103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-01 09:41 Nov 01 09:42:01 primo sudo[31103]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 06:34:13 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="4afef88585183bd857d5aee3dd000abc"