Mar 09 16:48:00 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:00 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:48:00 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:00 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:10 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:10 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:48:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:20 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:48:20 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:20 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:30 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:30 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:48:40 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:40 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:48:40 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:40 volumio volumio[1086]: info: Listing playlists Mar 09 16:48:50 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:48:50 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:49:00 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:00 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:49:00 volumio volumio[1086]: info: Listing playlists Mar 09 16:49:00 volumio volumio[1086]: info: Listing playlists Mar 09 16:49:10 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:10 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:49:12 volumio volumio[1086]: info: CorePlayQueue::getTrack 3 Mar 09 16:49:12 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:12 volumio volumio[1086]: info: Prefetching next song Mar 09 16:49:12 volumio volumio[1086]: info: DOING PREFETCH IN MPD Mar 09 16:49:12 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand add "NAS/NAS/!Lossless/ANNA ASTI/ANNA ASTI - 2023 - Царица/05. Ломка.flac" Mar 09 16:49:12 volumio volumio[1086]: info: Mar 09 16:49:12 volumio volumio[1086]: ---------------------------- MPD announces system playlist update Mar 09 16:49:12 volumio volumio[1086]: info: Ignoring MPD Status Update Mar 09 16:49:12 volumio volumio[1086]: info: sendMpdCommand add "NAS/NAS/!Lossless/ANNA ASTI/ANNA ASTI - 2023 - Царица/05. Ломка.flac" took 1 milliseconds Mar 09 16:49:12 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand consume 1 Mar 09 16:49:12 volumio volumio[1086]: info: ------------------------------ 1ms Mar 09 16:49:12 volumio volumio[1086]: info: sendMpdCommand consume 1 took 1 milliseconds Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::startPlaybackTimer Mar 09 16:49:17 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:17 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":62,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:17 volumio volumio[1086]: info: Mar 09 16:49:17 volumio volumio[1086]: ---------------------------- MPD announces system playlist update Mar 09 16:49:17 volumio volumio[1086]: info: Ignoring MPD Status Update Mar 09 16:49:17 volumio volumio[1086]: info: Mar 09 16:49:17 volumio volumio[1086]: ---------------------------- MPD announces state update: player Mar 09 16:49:17 volumio volumio[1086]: info: ControllerMpd::getState Mar 09 16:49:17 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand status Mar 09 16:49:17 volumio volumio[1086]: info: ------------------------------ 1ms Mar 09 16:49:17 volumio volumio[1086]: info: sendMpdCommand status took 1 milliseconds Mar 09 16:49:17 volumio volumio[1086]: verbose: ControllerMpd::parseState Mar 09 16:49:17 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 09 16:49:17 volumio volumio[1086]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 09 16:49:17 volumio volumio[1086]: verbose: ControllerMpd::parseTrackInfo Mar 09 16:49:17 volumio volumio[1086]: info: ControllerMpd::pushState Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::servicePushState Mar 09 16:49:17 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:17 volumio volumio[1086]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":181,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"651 Kbps","isStreaming":false,"title":"Ломка","artist":"ANNA ASTI","album":"Царица","uri":"NAS/NAS/!Lossless/ANNA ASTI/ANNA ASTI - 2023 - Царица/05. Ломка.flac","trackType":"flac"} Mar 09 16:49:17 volumio volumio[1086]: verbose: CURRENT POSITION 4 Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::syncState stateService play Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::syncState currentStatus play Mar 09 16:49:17 volumio volumio[1086]: info: Received an update from plugin. extracting info from payload Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:17 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:17 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:17 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:17 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:17 volumio volumio[1086]: info: ------------------------------ 8ms Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:17 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":62,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":62,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:18 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:20 volumio volumio[1086]: verbose: New Socket.io Connection to 192.168.0.59 from 192.168.0.45 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.3 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:20 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetVisibleSources Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:20 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 09 16:49:20 volumio volumio[1086]: info: Received Get System Info Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 09 16:49:20 volumio volumio[1086]: info: Discovery: Getting this device information Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:20 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:20 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:20 volumio volumio[1086]: info: Listing playlists Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::volumioGetQueue Mar 09 16:49:20 volumio volumio[1086]: info: CoreStateMachine::getQueue Mar 09 16:49:20 volumio volumio[1086]: info: CorePlayQueue::getQueue Mar 09 16:49:20 volumio volumio[1086]: info: Listing playlists Mar 09 16:49:20 volumio volumio[1086]: info: Listing playlists Mar 09 16:49:20 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , alsavolume Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: Set volume "44" [object Object] Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: set volume to integer value 44 Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,44 Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: vol_44! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: vol_44! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: volume=44 Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is 44 Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":44} Mar 09 16:49:21 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:21 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":44} Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":44,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:21 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:21 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:21 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:21 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:21 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":44,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:21 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":44,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":44,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , alsavolume Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: Set volume "53" [object Object] Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: set volume to integer value 53 Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,53 Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: vol_53! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: vol_53! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: volume=53 Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is 53 Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":53} Mar 09 16:49:22 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:22 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":53} Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":53,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:22 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:22 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:22 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:22 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:22 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":53,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:22 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":53,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":53,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:23 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , alsavolume Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: Set volume "47" [object Object] Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] alsavolume: set volume to integer value 47 Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,47 Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: vol_47! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: vol_47! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: volume=47 Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is 47 Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":47} Mar 09 16:49:24 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:24 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":47} Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":47,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:24 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:24 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:24 volumio volumio[1086]: info: CoreStateMachine::pushState Mar 09 16:49:24 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:24 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - play Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: send source,PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: PC-USB Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: pcusb! Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":47,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":47,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is pc_usb Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":47,"mute":false,"power":"on","Powering":"up","source":"pc_usb"} Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: freq=44.1K Mar 09 16:49:24 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: freq=44.1K Mar 09 16:49:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 09 16:49:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Mar 09 16:49:30 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState Mar 09 16:49:30 volumio volumio[1086]: info: CorePlayQueue::getTrack 4 Mar 09 16:49:31 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] closePorts: closing TCP/IP Mar 09 16:49:31 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] resetVolumeSettings: Volume settings have been reset. Mar 09 16:49:31 volumio volumio[1086]: error: Plugin serialampcontroller does not return adequate promise from onStop: please update! Mar 09 16:49:31 volumio volumio[1086]: info: Disabling plugin serialampcontroller Mar 09 16:49:31 volumio volumio[1086]: info: Done. Mar 09 16:49:31 volumio volumio[1086]: info: [SERIALAMPCONTROLLER] closePorts: closed TCP/IP socket Mar 09 16:49:34 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , alsavolume Mar 09 16:49:34 volumio volumio[1086]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 09 16:49:34 volumio volumio[1086]: TypeError: Cannot read properties of undefined (reading 'then') Mar 09 16:49:34 volumio volumio[1086]: at CoreCommandRouter.volumiosetvolume (/volumio/app/index.js:136:10) Mar 09 16:49:34 volumio volumio[1086]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:304:33) Mar 09 16:49:34 volumio volumio[1086]: at Socket.emit (node:events:514:28) Mar 09 16:49:34 volumio volumio[1086]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Mar 09 16:49:34 volumio volumio[1086]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 09 16:49:34 volumio volumio[1086]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 09 16:49:35 volumio sudo[7748]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-03-09 16:48' Mar 09 16:49:35 volumio sudo[7748]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="c4e184d4f6f6bde0af8ddd9d7eadaa6e3b46e745" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a7a6e4ee756971d9f8dea25279344ff5d3ab03d8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed Feb 12 11:20:36 UTC 2025" VOLUMIO_VERSION="0.035" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="263951139c9246e32bb1521174a0ca82"