-- Logs begin at Wed 2026-01-28 15:08:35 UTC, end at Wed 2026-01-28 15:22:02 UTC. --
Jan 28 15:21:05 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: youtube2 , handleBrowseUri
Jan 28 15:21:05 primo volumio[5933]: info: [youtube2-browse] browseUri: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:06 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:06 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:06 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:06 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:06.935Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2898068
Jan 28 15:21:06 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:06.939Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2898068
Jan 28 15:21:14 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:14 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:14 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:14 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:14.062Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826180
Jan 28 15:21:14 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:14.066Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826180
Jan 28 15:21:17 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::ClearQueue
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::stop
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::stPlaybackTimer
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::updateTrackBlock
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::getTrackBlock
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:17 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:17 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::serviceStop
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::serviceStop
Jan 28 15:21:17 primo volumio[5933]: info: [1769613677969] ControllerWebradio::stop
Jan 28 15:21:17 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand stop
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::clearPlayQueue
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::saveQueue
Jan 28 15:21:17 primo volumio[5933]: info: CoreCommandRouter::volumioPushQueue
Jan 28 15:21:17 primo volumio[5933]: info: CoreStateMachine::addQueueItems
Jan 28 15:21:17 primo volumio[5933]: info: CorePlayQueue::addQueueItems
Jan 28 15:21:17 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:17 primo volumio[5933]: info: Adding Item to queue: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D
Jan 28 15:21:17 primo volumio[5933]: info: Exploding uri youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D in service youtube2
Jan 28 15:21:17 primo volumio[5933]: info: [youtube2-browse] explodeUri: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info:
Jan 28 15:21:18 primo volumio[5933]: ---------------------------- MPD announces state update: player
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand stop took 89 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::getState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand status
Jan 28 15:21:18 primo volumio[5933]: info:
Jan 28 15:21:18 primo volumio[5933]: ---------------------------- MPD announces state update: player
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::getState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand status
Jan 28 15:21:18 primo volumio[5933]: info:
Jan 28 15:21:18 primo volumio[5933]: ---------------------------- MPD announces state update: player
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::getState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand status
Jan 28 15:21:18 primo volumio[5933]: info:
Jan 28 15:21:18 primo volumio[5933]: ---------------------------- MPD announces state update: player
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::getState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand status
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand status took 21 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand status took 17 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand status took 14 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand status took 10 milliseconds
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseState
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand playlistinfo took 8 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand playlistinfo took 8 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand playlistinfo took 8 milliseconds
Jan 28 15:21:18 primo volumio[5933]: info: sendMpdCommand playlistinfo took 7 milliseconds
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseTrackInfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseTrackInfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseTrackInfo
Jan 28 15:21:18 primo volumio[5933]: verbose: ControllerMpd::parseTrackInfo
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::servicePushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"De/Vision - Not In My Nature","artist":"Radio-DarkFire","album":null,"uri":"http://37.59.82.8:8344/stream1","trackType":""}
Jan 28 15:21:18 primo volumio[5933]: verbose: CURRENT POSITION 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState stateService stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState currentStatus stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: No code
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::servicePushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"De/Vision - Not In My Nature","artist":"Radio-DarkFire","album":null,"uri":"http://37.59.82.8:8344/stream1","trackType":""}
Jan 28 15:21:18 primo volumio[5933]: verbose: CURRENT POSITION 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState stateService stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState currentStatus stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: No code
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::servicePushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"De/Vision - Not In My Nature","artist":"Radio-DarkFire","album":null,"uri":"http://37.59.82.8:8344/stream1","trackType":""}
Jan 28 15:21:18 primo volumio[5933]: verbose: CURRENT POSITION 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState stateService stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState currentStatus stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: No code
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: ControllerMpd::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::servicePushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"De/Vision - Not In My Nature","artist":"Radio-DarkFire","album":null,"uri":"http://37.59.82.8:8344/stream1","trackType":""}
Jan 28 15:21:18 primo volumio[5933]: verbose: CURRENT POSITION 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState stateService stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::syncState currentStatus stop
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: No code
Jan 28 15:21:18 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:21:18 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:18 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:21:18 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:21:18 primo volumio[5933]: info: ------------------------------ 457ms
Jan 28 15:21:18 primo volumio[5933]: info: ------------------------------ 457ms
Jan 28 15:21:18 primo volumio[5933]: info: ------------------------------ 454ms
Jan 28 15:21:18 primo volumio[5933]: info: ------------------------------ 452ms
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:21:18 primo volumio[5933]: info: MCU Signalled Playback Inactive
Jan 28 15:21:21 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:21 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:21 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:21 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:21.153Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826078
Jan 28 15:21:21 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:21.156Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826078
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::volumioPushQueue
Jan 28 15:21:21 primo volumio[5933]: info: CorePlayQueue::saveQueue
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::updateTrackBlock
Jan 28 15:21:21 primo volumio[5933]: info: CorePlayQueue::getTrackBlock
Jan 28 15:21:21 primo volumio[5933]: info: CoreCommandRouter::volumioPlay
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::play index 0
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::stop
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::play index undefined
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:21 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:21 primo volumio[5933]: info: CoreStateMachine::startPlaybackTimer
Jan 28 15:21:21 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:21 primo volumio[5933]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Lady%20Gaga%2C%20Bruno%20Mars%20-%20Die%20With%20A%20Smile%20(Official%20Music%20Video)%22%2C%22artist%22%3A%22Lady%20Gaga%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FkPa7bsKwL-c%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAQiJs48T0874m4PwpyLlb_MVZ0zg%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D
Jan 28 15:21:22 primo ntpd[3287]: 95.242.98.72 local addr 192.168.1.128 ->
Jan 28 15:21:22 primo volumio[5933]: error: [youtube2] Error in VideoModel.getInfo(kPa7bsKwL-c): No valid URL to decipher Error: No valid URL to decipher
Jan 28 15:21:22 primo volumio[5933]: at _Player.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:34251:13)
Jan 28 15:21:22 primo volumio[5933]: at _Format.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:23105:19)
Jan 28 15:21:22 primo volumio[5933]: at VideoModel._VideoModel_chooseFormat (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:86:39)
Jan 28 15:21:22 primo volumio[5933]: at VideoModel.getPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:69:116)
Jan 28 15:21:22 primo volumio[5933]: at runMicrotasks ()
Jan 28 15:21:22 primo volumio[5933]: at processTicksAndRejections (internal/process/task_queues.js:95:5)
Jan 28 15:21:22 primo volumio[5933]: at async Function.getPlaybackInfoFromUri (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:167:19)
Jan 28 15:21:22 primo volumio[5933]: at async PlayController.clearAddPlayTrack (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:89:49)
Jan 28 15:21:28 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:28 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:28 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:28 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:28 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:28.239Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2a0c058
Jan 28 15:21:28 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:28.246Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2a0c058
Jan 28 15:21:31 primo volumio[5933]: info: CoreCommandRouter::volumioPlay
Jan 28 15:21:31 primo volumio[5933]: info: CoreStateMachine::play index undefined
Jan 28 15:21:31 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:31 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:31 primo volumio[5933]: info: CoreStateMachine::startPlaybackTimer
Jan 28 15:21:31 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:31 primo volumio[5933]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Lady%20Gaga%2C%20Bruno%20Mars%20-%20Die%20With%20A%20Smile%20(Official%20Music%20Video)%22%2C%22artist%22%3A%22Lady%20Gaga%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FkPa7bsKwL-c%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAQiJs48T0874m4PwpyLlb_MVZ0zg%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D
Jan 28 15:21:32 primo volumio[5933]: error: [youtube2] Error in VideoModel.getInfo(kPa7bsKwL-c): No valid URL to decipher Error: No valid URL to decipher
Jan 28 15:21:32 primo volumio[5933]: at _Player.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:34251:13)
Jan 28 15:21:32 primo volumio[5933]: at _Format.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:23105:19)
Jan 28 15:21:32 primo volumio[5933]: at VideoModel._VideoModel_chooseFormat (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:86:39)
Jan 28 15:21:32 primo volumio[5933]: at VideoModel.getPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:69:116)
Jan 28 15:21:32 primo volumio[5933]: at runMicrotasks ()
Jan 28 15:21:32 primo volumio[5933]: at processTicksAndRejections (internal/process/task_queues.js:95:5)
Jan 28 15:21:32 primo volumio[5933]: at async Function.getPlaybackInfoFromUri (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:167:19)
Jan 28 15:21:32 primo volumio[5933]: at async PlayController.clearAddPlayTrack (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:89:49)
Jan 28 15:21:35 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:35 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:35 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:35 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:35 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:35.375Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2a0c090
Jan 28 15:21:35 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:35.380Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2a0c090
Jan 28 15:21:38 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:38 primo volumio[5933]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::ClearQueue
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::stop
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::clearPlayQueue
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::saveQueue
Jan 28 15:21:38 primo volumio[5933]: info: CoreCommandRouter::volumioPushQueue
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::addQueueItems
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::addQueueItems
Jan 28 15:21:38 primo volumio[5933]: info: Preload queue cleared
Jan 28 15:21:38 primo volumio[5933]: info: Adding Item to queue: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D
Jan 28 15:21:38 primo volumio[5933]: info: Using cached record of: youtube2/generic@endpoint:o=%7B%22type%22%3A%22browse%22%2C%22payload%22%3A%7B%22browseId%22%3A%22UC-9-kyTW8ZkZNDHQJ6FgpwQ%22%7D%7D
Jan 28 15:21:38 primo volumio[5933]: info: CoreCommandRouter::volumioPushQueue
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::saveQueue
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::updateTrackBlock
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::getTrackBlock
Jan 28 15:21:38 primo volumio[5933]: info: CoreCommandRouter::volumioPlay
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::play index 0
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::stop
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::play index undefined
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::setConsumeUpdateService undefined
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:38 primo volumio[5933]: info: CoreStateMachine::startPlaybackTimer
Jan 28 15:21:38 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:38 primo volumio[5933]: info: [youtube2-play] clearAddPlayTrack: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Lady%20Gaga%2C%20Bruno%20Mars%20-%20Die%20With%20A%20Smile%20(Official%20Music%20Video)%22%2C%22artist%22%3A%22Lady%20Gaga%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FkPa7bsKwL-c%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAQiJs48T0874m4PwpyLlb_MVZ0zg%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22kPa7bsKwL-c%22%2C%22playlistId%22%3A%22RDCLAK5uy_ngV593f_RWoumLPyvjLhVrSkxBlLpKKAE%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A0%7D%7D%7D
Jan 28 15:21:38 primo volumio[5933]: error: [youtube2] Error in VideoModel.getInfo(kPa7bsKwL-c): No valid URL to decipher Error: No valid URL to decipher
Jan 28 15:21:38 primo volumio[5933]: at _Player.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:34251:13)
Jan 28 15:21:38 primo volumio[5933]: at _Format.decipher (/data/plugins/music_service/youtube2/node_modules/volumio-youtubei.js/bundle/node.cjs:23105:19)
Jan 28 15:21:38 primo volumio[5933]: at VideoModel._VideoModel_chooseFormat (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:86:39)
Jan 28 15:21:38 primo volumio[5933]: at VideoModel.getPlaybackInfo (/data/plugins/music_service/youtube2/dist/lib/model/VideoModel.js:69:116)
Jan 28 15:21:38 primo volumio[5933]: at runMicrotasks ()
Jan 28 15:21:38 primo volumio[5933]: at processTicksAndRejections (internal/process/task_queues.js:95:5)
Jan 28 15:21:38 primo volumio[5933]: at async Function.getPlaybackInfoFromUri (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:167:19)
Jan 28 15:21:38 primo volumio[5933]: at async PlayController.clearAddPlayTrack (/data/plugins/music_service/youtube2/dist/lib/controller/play/PlayController.js:89:49)
Jan 28 15:21:42 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:42 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:42 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:42 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:42 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:42.472Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826070
Jan 28 15:21:42 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:42.475Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x2826070
Jan 28 15:21:49 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:49 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:49 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:49 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:49 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:49.604Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x28260a8
Jan 28 15:21:49 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:49.606Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x28260a8
Jan 28 15:21:52 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Jan 28 15:21:52 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Jan 28 15:21:56 primo volumio[5933]: info: Received Get System Info
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Jan 28 15:21:56 primo volumio[5933]: info: Discovery: Getting this device information
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:21:56 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Jan 28 15:21:56 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Jan 28 15:21:56 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:56.710Z level=INFO msg="BLE descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x29166c0
Jan 28 15:21:56 primo volumio5-onboarding[4737]: time=2026-01-28T15:21:56.713Z level=INFO msg="mDNS descriptor updated" deviceId=603e8d5769478a202943b1fa74ec1dfd deviceName=Primo deviceModel=0x29166c0
Jan 28 15:22:00 primo volumio[5933]: info: Enabling plugin fusiondsp
Jan 28 15:22:00 primo volumio[5933]: info: Loading plugin "fusiondsp"...
Jan 28 15:22:00 primo volumio[5933]: info: Applying required configuration parameters for plugin fusiondsp
Jan 28 15:22:00 primo volumio[5933]: info: Preparing to generate the ALSA configuration file
Jan 28 15:22:00 primo volumio[5933]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Jan 28 15:22:00 primo volumio[5933]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Jan 28 15:22:00 primo volumio[5933]: info: Reading ALSA contributions from plugins.
Jan 28 15:22:00 primo volumio[5933]: info: Asound.conf file unchanged, so no further update is needed
Jan 28 15:22:00 primo volumio[5933]: info: Output device has changed, restarting MPD
Jan 28 15:22:00 primo sudo[8684]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Jan 28 15:22:00 primo sudo[8684]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:00 primo sudo[8684]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:00 primo volumio[5933]: info: Output device has changed, restarting Shairport Sync
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 28 15:22:00 primo sudo[8687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Jan 28 15:22:00 primo sudo[8687]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:00 primo systemd[1]: Stopping Music Player Daemon...
Jan 28 15:22:00 primo volumio[5933]: No protocol specified
Jan 28 15:22:00 primo volumio[5933]: xcb_connection_has_error() returned true
Jan 28 15:22:00 primo volumio[5933]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Jan 28 15:22:00 primo volumio[5933]: No protocol specified
Jan 28 15:22:00 primo volumio[5933]: xcb_connection_has_error() returned true
Jan 28 15:22:00 primo volumio[5933]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:00 primo volumio[5933]: info: QobuzConnect: setDeactiveState invoked
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:22:00 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:00 primo volumio[5933]: info: Reconfiguring and Restarting RAAT Plugin due to audio device changes
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:00 primo vtcs[6753]: [2026-01-28 15:22:00.753] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected
Jan 28 15:22:00 primo vtcs[6753]: [2026-01-28 15:22:00.753] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE
Jan 28 15:22:00 primo kernel: aml_tdm_open
Jan 28 15:22:00 primo kernel: Not init audio effects
Jan 28 15:22:00 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1
Jan 28 15:22:00 primo kernel: tdm playback mute: 1, lane_cnt = 8
Jan 28 15:22:00 primo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1
Jan 28 15:22:00 primo volumio[5933]: info: PLUGIN START: fusiondsp
Jan 28 15:22:00 primo volumio[5933]: info: Loading i18n strings for locale it
Jan 28 15:22:00 primo sudo[8696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Jan 28 15:22:00 primo sudo[8696]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Jan 28 15:22:00 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:00 primo volumio[5933]: info: FusionDsp - mixtype--------------------- Hardware
Jan 28 15:22:00 primo volumio[5933]: info: Preparing to generate the ALSA configuration file
Jan 28 15:22:00 primo systemd[1]: Stopping Volumio Tidal Connect Service...
Jan 28 15:22:00 primo systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM
Jan 28 15:22:00 primo systemd[1]: vtcs.service: Succeeded.
Jan 28 15:22:00 primo systemd[1]: Stopped Volumio Tidal Connect Service.
Jan 28 15:22:00 primo volumio[5933]: info: Done.
Jan 28 15:22:00 primo sudo[8696]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:00 primo systemd[1]: mpd.service: Succeeded.
Jan 28 15:22:00 primo systemd[1]: Stopped Music Player Daemon.
Jan 28 15:22:00 primo systemd[1]: Starting Music Player Daemon...
Jan 28 15:22:00 primo sudo[8700]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Jan 28 15:22:00 primo sudo[8700]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:01 primo sudo[8700]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:01 primo volumio[5933]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Jan 28 15:22:01 primo volumio[5933]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Jan 28 15:22:01 primo volumio[5933]: info: Reading ALSA contributions from plugins.
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: running
Jan 28 15:22:01 primo sudo[8718]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Jan 28 15:22:01 primo sudo[8718]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: running
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: running
Jan 28 15:22:01 primo sudo[8702]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Jan 28 15:22:01 primo sudo[8702]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:01 primo sudo[8718]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:01 primo volumio[5933]: info: MPD Permissions set
Jan 28 15:22:01 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:22:01 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:22:01 primo sudo[8702]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:22:01 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:01 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:22:01 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:22:01 primo volumio[5933]: info: CoreStateMachine::pushState
Jan 28 15:22:01 primo sudo[8721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Jan 28 15:22:01 primo sudo[8721]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jan 28 15:22:01 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::volumioPushState
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:22:01 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:01 primo volumio[5933]: info: MRS: Pushing multiroomSync output update for this device
Jan 28 15:22:01 primo volumio[5933]: info: MRS: Pushing multiroomSync output
Jan 28 15:22:01 primo systemd[1]: Stopping Volumio Qobuz Connect Service...
Jan 28 15:22:01 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:22:01 primo volumio[5933]: info: Updating RAAT Signal Path
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: running
Jan 28 15:22:01 primo qobuz-connect[6733]: 20260128 15:22:01.314 [6733.6733] INFO SampleApp: Stopping Local configuration server
Jan 28 15:22:01 primo qobuz-connect[6733]: 20260128 15:22:01.324 [6733.6733] INFO SampleApp: shat down connection on UNIX socket
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: Not Reporting Auto name since its the default one
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo systemd[1]: qobuz-connect.service: Succeeded.
Jan 28 15:22:01 primo systemd[1]: Stopped Volumio Qobuz Connect Service.
Jan 28 15:22:01 primo systemd[1]: Started Volumio Qobuz Connect Service.
Jan 28 15:22:01 primo sudo[8721]: pam_unix(sudo:session): session closed for user root
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Jan 28 15:22:01 primo volumio[5933]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
Jan 28 15:22:01 primo volumio[5933]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected
Jan 28 15:22:01 primo volumio[5933]: info: QobuzConnect: setDeactiveState invoked
Jan 28 15:22:01 primo volumio[5933]: info: CoreCommandRouter::volumioGetState
Jan 28 15:22:01 primo volumio[5933]: info: CorePlayQueue::getTrack 0
Jan 28 15:22:01 primo volumio[5933]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 28 15:22:01 primo volumio[5933]: TypeError: Cannot read property 'off' of undefined
Jan 28 15:22:01 primo volumio[5933]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15)
Jan 28 15:22:01 primo volumio[5933]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30)
Jan 28 15:22:01 primo volumio[5933]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8)
Jan 28 15:22:01 primo volumio[5933]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29)
Jan 28 15:22:01 primo volumio[5933]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1412:47)
Jan 28 15:22:01 primo volumio[5933]: at Socket.emit (events.js:400:28)
Jan 28 15:22:01 primo volumio[5933]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Jan 28 15:22:01 primo volumio[5933]: at processTicksAndRejections (internal/process/task_queues.js:77:11)
Jan 28 15:22:01 primo volumio[5933]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jan 28 15:22:02 primo sudo[8747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-28 15:21
Jan 28 15:22:02 primo sudo[8747]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4"
VOLUMIO_ARCH="armv7"
VOLUMIO_VARIANT="primo2rev2"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 07:52:21 PM CET"
VOLUMIO_VERSION="3.886"
VOLUMIO_HARDWARE="mp1"
VOLUMIO_DEVICENAME="Volumio MP1"
VOLUMIO_VENDOR_MODEL="Volumio Primo"
VOLUMIO_VENDOR="Volumio"
VOLUMIO_MODEL="Primo"
VOLUMIO_HASH="060c5b31331b90c840ee52059a8e3db0"