-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Sun 2026-02-22 10:20:01 JST. -- Feb 22 10:19:04 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 22 10:19:13 primo-plus volumio[977]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 22 10:19:13 primo-plus volumio[977]: info: Received Get System Version Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 22 10:19:13 primo-plus volumio[977]: info: Received Get System Info Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 22 10:19:13 primo-plus volumio[977]: info: Discovery: Getting this device information Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:13 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:13 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Feb 22 10:19:18 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:18 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:18 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:18 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:18 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:18 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:18.965+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=251 volume=36 Feb 22 10:19:18 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:18.965+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:18 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:18 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Feb 22 10:19:18 primo-plus volumio[977]: SPOTIFY: SPOTIFY VOLUME 54 Feb 22 10:19:18 primo-plus volumio[977]: SPOTIFY: VOLUMIO VOLUME 36 Feb 22 10:19:18 primo-plus volumio[977]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 22 10:19:18 primo-plus volumio[977]: info: Setting Spotify Volume from Volumio: 36 Feb 22 10:19:18 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:18 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:18 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:18 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:18 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:18 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:18 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:18.998+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=251 volume=36 Feb 22 10:19:18 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:18.998+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:19 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: inputs , alsavolume Feb 22 10:19:19 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:19 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:19 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:19 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:19 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:19 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:19.135+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=251 volume=38 Feb 22 10:19:19 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:19.136+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:19 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: SPOTIFY VOLUME 36 Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: VOLUMIO VOLUME 38 Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: DELTA VOLUME ENOUGH: true Feb 22 10:19:19 primo-plus volumio[977]: info: Setting Spotify Volume from Volumio: 38 Feb 22 10:19:19 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:19 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:19 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:19 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:19 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:19 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:19 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:19.226+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=251 volume=38 Feb 22 10:19:19 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:19.227+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:19 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:19 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:20 primo-plus volumio[977]: SPOTIFY: SETTING SPOTIFY VOLUME 38 Feb 22 10:19:20 primo-plus volumio[977]: info: Sending Spotify command with payload to local API: /player/volume Feb 22 10:19:20 primo-plus go-librespot[3234]: time="2026-02-22T10:19:20+09:00" level=debug msg="update volume requested to 24903/65535" Feb 22 10:19:20 primo-plus go-librespot[3234]: time="2026-02-22T10:19:20+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Feb 22 10:19:20 primo-plus go-librespot[3234]: time="2026-02-22T10:19:20+09:00" level=trace msg="emitting websocket event: volume" Feb 22 10:19:20 primo-plus volumio[977]: SPOTIFY: received: {"type":"volume","data":{"value":38,"max":100}} Feb 22 10:19:20 primo-plus volumio[977]: SPOTIFY: RECEIVED SPOTIFY VOLUME 38 Feb 22 10:19:21 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 22 10:19:21 primo-plus volumio[977]: No protocol specified Feb 22 10:19:21 primo-plus volumio[977]: xcb_connection_has_error() returned true Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 22 10:19:21 primo-plus volumio[977]: No protocol specified Feb 22 10:19:21 primo-plus volumio[977]: xcb_connection_has_error() returned true Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: raat , getAdditionalUiSection Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: inputs , getAdditionalUiSection Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 10:19:21 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 22 10:19:22 primo-plus go-librespot[3234]: time="2026-02-22T10:19:22+09:00" level=trace msg="sent dealer ping" Feb 22 10:19:22 primo-plus go-librespot[3234]: time="2026-02-22T10:19:22+09:00" level=trace msg="received dealer pong" Feb 22 10:19:30 primo-plus volumio[977]: info: CoreCommandRouter::volumioNext Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::next Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CorePlayQueue::getTrack 1 Feb 22 10:19:30 primo-plus volumio[977]: info: CoreCommandRouter::volumioNext Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::next Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:30 primo-plus volumio[977]: info: CorePlayQueue::getTrack 1 Feb 22 10:19:31 primo-plus volumio[977]: info: CoreCommandRouter::volumioPrevious Feb 22 10:19:31 primo-plus volumio[977]: info: CoreStateMachine::previous Feb 22 10:19:31 primo-plus volumio[977]: info: CoreCommandRouter::volumioPlay Feb 22 10:19:31 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:31 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:31 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:31 primo-plus volumio[977]: info: CoreStateMachine::startPlaybackTimer Feb 22 10:19:31 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:31 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 10:19:31 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 10:19:31 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 10:19:31 primo-plus volumio[977]: info: [1771723171929] ControllerWebradio::clearAddPlayTrack Feb 22 10:19:31 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:31 primo-plus volumio[977]: info: sendMpdCommand stop took 1 milliseconds Feb 22 10:19:31 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 10:19:31 primo-plus volumio[977]: info: sendMpdCommand clear took 1 milliseconds Feb 22 10:19:31 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand load "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:31 primo-plus volumio[977]: info: Feb 22 10:19:31 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:31 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:31 primo-plus volumio[977]: info: Feb 22 10:19:31 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:31 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:31 primo-plus volumio[977]: info: Feb 22 10:19:31 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:31 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:31 primo-plus volumio[977]: error: Upnp client error: Error: This socket has been ended by the other party Feb 22 10:19:32 primo-plus volumio[977]: info: CoreCommandRouter::volumioPlay Feb 22 10:19:32 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:32 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:32 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:32 primo-plus volumio[977]: info: CoreStateMachine::startPlaybackTimer Feb 22 10:19:32 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:32 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 10:19:32 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 10:19:32 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 10:19:32 primo-plus volumio[977]: info: [1771723172975] ControllerWebradio::clearAddPlayTrack Feb 22 10:19:32 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:33 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 1879ms Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 1878ms Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 1876ms Feb 22 10:19:33 primo-plus volumio[977]: info: sendMpdCommand stop took 838 milliseconds Feb 22 10:19:33 primo-plus volumio[977]: info: sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" took 4 milliseconds Feb 22 10:19:33 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 10:19:33 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 10:19:33 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand play Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 9ms Feb 22 10:19:33 primo-plus volumio[977]: info: sendMpdCommand clear took 6 milliseconds Feb 22 10:19:33 primo-plus volumio[977]: info: sendMpdCommand play took 6 milliseconds Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 6ms Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 5ms Feb 22 10:19:33 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand load "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: info: Feb 22 10:19:33 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:33 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:33 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:33 primo-plus volumio[977]: info: ------------------------------ 7ms Feb 22 10:19:33 primo-plus volumio[977]: info: CoreCommandRouter::volumioPlay Feb 22 10:19:33 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:33 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:33 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:33 primo-plus volumio[977]: info: CoreStateMachine::startPlaybackTimer Feb 22 10:19:33 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:33 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 10:19:33 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 10:19:33 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 10:19:33 primo-plus volumio[977]: info: [1771723173924] ControllerWebradio::clearAddPlayTrack Feb 22 10:19:33 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:34 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetQueue Feb 22 10:19:34 primo-plus volumio[977]: info: CoreStateMachine::getQueue Feb 22 10:19:34 primo-plus volumio[977]: info: CorePlayQueue::getQueue Feb 22 10:19:35 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:35 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:35 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:35 primo-plus volumio[977]: info: ------------------------------ 1689ms Feb 22 10:19:35 primo-plus volumio[977]: info: ------------------------------ 1688ms Feb 22 10:19:35 primo-plus volumio[977]: info: sendMpdCommand stop took 1589 milliseconds Feb 22 10:19:35 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 10:19:35 primo-plus volumio[977]: info: Feb 22 10:19:35 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:35 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:35 primo-plus volumio[977]: info: Feb 22 10:19:35 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:35 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:35 primo-plus volumio[977]: info: sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" took 6 milliseconds Feb 22 10:19:35 primo-plus volumio[977]: info: sendMpdCommand clear took 3 milliseconds Feb 22 10:19:35 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 10:19:35 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand play Feb 22 10:19:35 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand load "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:35 primo-plus volumio[977]: info: Feb 22 10:19:35 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:35 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:35 primo-plus volumio[977]: info: Feb 22 10:19:35 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:35 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:35 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:35 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:35 primo-plus volumio[977]: info: ------------------------------ 8ms Feb 22 10:19:35 primo-plus volumio[977]: info: ------------------------------ 7ms Feb 22 10:19:35 primo-plus volumio[977]: info: sendMpdCommand play took 6 milliseconds Feb 22 10:19:37 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:37 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:37 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 1749ms Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 1747ms Feb 22 10:19:37 primo-plus volumio[977]: info: Feb 22 10:19:37 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:37 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:37 primo-plus volumio[977]: info: Feb 22 10:19:37 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:37 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:37 primo-plus volumio[977]: info: Feb 22 10:19:37 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:37 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:37 primo-plus volumio[977]: info: sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" took 7 milliseconds Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 4ms Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 4ms Feb 22 10:19:37 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 10:19:37 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand play Feb 22 10:19:37 primo-plus volumio[977]: info: Feb 22 10:19:37 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:37 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:37 primo-plus volumio[977]: info: Feb 22 10:19:37 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:37 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 10ms Feb 22 10:19:37 primo-plus volumio[977]: info: sendMpdCommand play took 4 milliseconds Feb 22 10:19:37 primo-plus volumio[977]: info: ------------------------------ 3ms Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 5 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 4 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 7 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 6 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 5 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus stop Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 36ms Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.100+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.100+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.102+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.102+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 52ms Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:39 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:39 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 49 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 53 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 53 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 12 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 12ms Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.156+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.157+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.157+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.157+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.158+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.158+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.162+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=0 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.162+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 109ms Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 109ms Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:39 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:39 primo-plus volumio[977]: info: Feb 22 10:19:39 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 90 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 89ms Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 80 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 79 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 77 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 31ms Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand status took 31 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.237+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=232 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.237+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.237+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=232 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.237+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.238+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=232 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.238+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 183ms Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 139ms Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 47 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 48 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 47 milliseconds Feb 22 10:19:39 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1108,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:39 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:39 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1234,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:39 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:39 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:39 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:39 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.292+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.293+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.294+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.294+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.295+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.296+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.299+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.297+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.297+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=281 volume=38 Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.300+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:39.302+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 197ms Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 195ms Feb 22 10:19:39 primo-plus volumio[977]: info: ------------------------------ 139ms Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:39 primo-plus volumio[977]: info: MCU Signalled Playback Active Feb 22 10:19:41 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:41 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:41 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:41 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:42 primo-plus volumio[977]: info: Preload queue cleared Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::ClearQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::stPlaybackTimer Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::updateTrackBlock Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrackBlock Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::serviceStop Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::serviceStop Feb 22 10:19:42 primo-plus volumio[977]: info: [1771723182075] ControllerWebradio::stop Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::clearPlayQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::saveQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::addQueueItems Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::addQueueItems Feb 22 10:19:42 primo-plus volumio[977]: info: Preload queue cleared Feb 22 10:19:42 primo-plus volumio[977]: info: Adding Item to queue: http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99235201 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.080+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=0 volume=38 Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.080+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::saveQueue Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::updateTrackBlock Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrackBlock Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPlay Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::play index 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::startPlaybackTimer Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 10:19:42 primo-plus volumio[977]: info: [1771723182111] ControllerWebradio::clearAddPlayTrack Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:42 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:42 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand stop took 63 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand stop took 28 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:42 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:42 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:42 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand status took 11 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand clear took 10 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand status took 5 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: info: sendMpdCommand status took 4 milliseconds Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99235201" Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:42 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:42 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 22 10:19:42 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:42 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:42 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:42 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:42 primo-plus volumio[977]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.182+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=0 volume=38 Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.183+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99235201" title=Www.spotify.com Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.185+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_STOPPED positionMs=0 volume=38 Feb 22 10:19:42 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:42.185+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99235201" title=Www.spotify.com Feb 22 10:19:42 primo-plus volumio[977]: info: ------------------------------ 55ms Feb 22 10:19:42 primo-plus volumio[977]: info: ------------------------------ 54ms Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:42 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:42 primo-plus volumio[977]: info: Feb 22 10:19:42 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:42 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:42 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:42 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:42 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:42 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:42 primo-plus volumio[977]: info: MCU Signalled Playback Inactive Feb 22 10:19:43 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:43 primo-plus volumio[977]: info: Feb 22 10:19:43 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:43 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 1359ms Feb 22 10:19:43 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 1357 milliseconds Feb 22 10:19:43 primo-plus volumio[977]: info: sendMpdCommand load "http://yp.shoutcast.com/sbin/tunein-station.m3u?id=99235201" took 1356 milliseconds Feb 22 10:19:43 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:43 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 10:19:43 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand play Feb 22 10:19:43 primo-plus volumio[977]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 1372ms Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 1309ms Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 1309ms Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 3ms Feb 22 10:19:43 primo-plus volumio[977]: info: Feb 22 10:19:43 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:43 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:43 primo-plus volumio[977]: info: Feb 22 10:19:43 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:43 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:43 primo-plus volumio[977]: info: sendMpdCommand play took 4 milliseconds Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 3ms Feb 22 10:19:43 primo-plus volumio[977]: info: ------------------------------ 2ms Feb 22 10:19:44 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:44 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:44 primo-plus volumio[977]: info: Feb 22 10:19:44 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:44 primo-plus volumio[977]: info: Feb 22 10:19:44 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:44 primo-plus volumio[977]: error: MPD returned error for command status: Failed to decode http://listen.shoutcast.com/wwwspotifycom; got HTTP status 404 Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand status took 9 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:44 primo-plus volumio[977]: info: Feb 22 10:19:44 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:44 primo-plus volumio[977]: error: MPD returned error for command status: Failed to decode http://listen.shoutcast.com/wwwspotifycom; got HTTP status 404 Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clearerror Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand status took 16 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand clearerror took 10 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 8 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand status took 6 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:44 primo-plus volumio[977]: 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":"wwwspotifycom","artist":"Www.spotify.com","album":null,"uri":"http://listen.shoutcast.com/wwwspotifycom","trackType":""} Feb 22 10:19:44 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: No code Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.692+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2501 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.693+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.693+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2501 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.693+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.694+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2501 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.694+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio[977]: info: ------------------------------ 56ms Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand clearerror took 66 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 63 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 62 milliseconds Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:44 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:44 primo-plus volumio[977]: 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":"wwwspotifycom","artist":"Www.spotify.com","album":null,"uri":"http://listen.shoutcast.com/wwwspotifycom","trackType":""} Feb 22 10:19:44 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: No code Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:44 primo-plus volumio[977]: 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":"wwwspotifycom","artist":"Www.spotify.com","album":null,"uri":"http://listen.shoutcast.com/wwwspotifycom","trackType":""} Feb 22 10:19:44 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus stop Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio[977]: info: No code Feb 22 10:19:44 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:44 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:44 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.765+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2624 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.765+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.765+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2624 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.766+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.766+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2624 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.766+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.766+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2624 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.767+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.767+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=2624 volume=38 Feb 22 10:19:44 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:44.767+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:44 primo-plus volumio[977]: info: ------------------------------ 135ms Feb 22 10:19:44 primo-plus volumio[977]: info: ------------------------------ 125ms Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:44 primo-plus volumio[977]: info: MCU Signalled Playback Active Feb 22 10:19:46 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:46 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:46 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:46 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:48 primo-plus volumio[977]: info: Preload queue cleared Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::ClearQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::clearPlayQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::saveQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::addQueueItems Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::addQueueItems Feb 22 10:19:48 primo-plus volumio[977]: info: Preload queue cleared Feb 22 10:19:48 primo-plus volumio[977]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s333149 Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::saveQueue Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::updateTrackBlock Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::getTrackBlock Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::volumioPlay Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::play index 0 Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::stop Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::play index undefined Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:48 primo-plus volumio[977]: info: CoreStateMachine::startPlaybackTimer Feb 22 10:19:48 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetVisibleSources Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 22 10:19:48 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 22 10:19:48 primo-plus volumio[977]: info: [1771723188736] ControllerWebradio::clearAddPlayTrack Feb 22 10:19:48 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand stop Feb 22 10:19:48 primo-plus volumio[977]: info: sendMpdCommand stop took 8 milliseconds Feb 22 10:19:48 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand clear Feb 22 10:19:48 primo-plus volumio[977]: info: Feb 22 10:19:48 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:48 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:48 primo-plus volumio[977]: info: sendMpdCommand clear took 2 milliseconds Feb 22 10:19:48 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand load "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:48 primo-plus volumio[977]: info: Feb 22 10:19:48 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:48 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:48 primo-plus volumio[977]: info: Feb 22 10:19:48 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:48 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:50 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 2169ms Feb 22 10:19:50 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" Feb 22 10:19:50 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:50 primo-plus volumio[977]: error: updateQueue error: null Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 2169ms Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 2168ms Feb 22 10:19:50 primo-plus volumio[977]: Upnp client error: Error: This socket has been ended by the other party Feb 22 10:19:50 primo-plus volumio[977]: info: Feb 22 10:19:50 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:50 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:50 primo-plus volumio[977]: info: sendMpdCommand add "https://spotify.stream.laut.fm/spotify?ref=radiodns" took 5 milliseconds Feb 22 10:19:50 primo-plus volumio[977]: info: CoreStateMachine::setConsumeUpdateService mpd Feb 22 10:19:50 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand play Feb 22 10:19:50 primo-plus volumio[977]: info: Feb 22 10:19:50 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:50 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:50 primo-plus volumio[977]: info: Feb 22 10:19:50 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:50 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 6ms Feb 22 10:19:50 primo-plus volumio[977]: info: sendMpdCommand play took 4 milliseconds Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 3ms Feb 22 10:19:50 primo-plus volumio[977]: info: ------------------------------ 4ms Feb 22 10:19:52 primo-plus go-librespot[3234]: time="2026-02-22T10:19:52+09:00" level=trace msg="sent dealer ping" Feb 22 10:19:52 primo-plus go-librespot[3234]: time="2026-02-22T10:19:52+09:00" level=trace msg="received dealer pong" Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 6 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 9 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 8 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 4 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 4 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 3 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus stop Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 17ms Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 7 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 6 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 3 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"spotify?ref=radiodns","artist":null,"album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.676+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.677+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.677+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.677+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.677+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.678+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.678+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.678+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.679+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.683+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.683+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.684+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.684+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title=spotify Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 99ms Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 97ms Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 94ms Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:52 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 89 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.749+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.749+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.750+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=79 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.750+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 130ms Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:52 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces system playlist update Feb 22 10:19:52 primo-plus volumio[977]: info: Ignoring MPD Status Update Feb 22 10:19:52 primo-plus volumio[977]: info: Feb 22 10:19:52 primo-plus volumio[977]: ---------------------------- MPD announces state update: player Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::getState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand status Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 102ms Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 101 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 63ms Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 62 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 62ms Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand status took 61 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseState Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::sendMpdCommand playlistinfo Feb 22 10:19:52 primo-plus volumio[977]: info: sendMpdCommand playlistinfo took 2 milliseconds Feb 22 10:19:52 primo-plus volumio[977]: verbose: ControllerMpd::parseTrackInfo Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1234,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: ControllerMpd::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::servicePushState Feb 22 10:19:52 primo-plus volumio[977]: info: CorePlayQueue::getTrack 0 Feb 22 10:19:52 primo-plus volumio[977]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1360,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"The Marías - No One Noticed","artist":"spotify","album":null,"uri":"https://spotify.stream.laut.fm/spotify?ref=radiodns","trackType":""} Feb 22 10:19:52 primo-plus volumio[977]: verbose: CURRENT POSITION 0 Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState stateService play Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::syncState currentStatus play Feb 22 10:19:52 primo-plus volumio[977]: info: Received an update from plugin. extracting info from payload Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio[977]: info: CoreStateMachine::pushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioPushState Feb 22 10:19:52 primo-plus volumio[977]: info: CoreCommandRouter::volumioGetState Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output update for this device Feb 22 10:19:52 primo-plus volumio[977]: info: MRS: Pushing multiroomSync output Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.853+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=270 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.853+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.855+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=270 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.855+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.857+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=270 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.858+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.858+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=270 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.858+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.858+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" state=STATUS_PLAYING positionMs=270 volume=38 Feb 22 10:19:52 primo-plus volumio5-onboarding[1437]: time=2026-02-22T10:19:52.859+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.11.9:57488 @ 0x32d5950" id="https://spotify.stream.laut.fm/spotify?ref=radiodns" title="The Marías - No One Noticed" Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 155ms Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 117ms Feb 22 10:19:52 primo-plus volumio[977]: info: ------------------------------ 116ms Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Signalling Playback active due to playback status change Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: info: Updating RAAT Signal Path Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:52 primo-plus volumio[977]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Feb 22 10:19:54 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:54 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:19:54 primo-plus volumio[977]: info: Executing endpoint metavolumio Feb 22 10:19:54 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 22 10:20:01 primo-plus volumio[977]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: Starting cast device: AMBEO-Soundbar-Plus-bf916d7da4b4eca38702928b5792ab92 Feb 22 10:20:01 primo-plus volumio[977]: info: Enabled audio output: AMBEO-Soundbar-Plus-bf916d7da4b4eca38702928b5792ab92 Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: Setting this device as Streaming Server Feb 22 10:20:01 primo-plus volumio[977]: info: Feb 22 10:20:01 primo-plus volumio[977]: [1771723201320] ---------------------------- MRS: Setting Streaming Server Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: enable multiroom server output Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: Set multiroom target PCM to volumioMultiRoom Feb 22 10:20:01 primo-plus volumio[977]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: Connected to cast device: AMBEO-Soundbar-Plus-bf916d7da4b4eca38702928b5792ab92 Feb 22 10:20:01 primo-plus volumio[977]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Feb 22 10:20:01 primo-plus volumio[977]: info: MRS: STARTING volumioStreaming Feb 22 10:20:01 primo-plus sudo[6280]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 22 10:20:01 primo-plus sudo[6280]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 10:20:01 primo-plus sudo[6280]: pam_unix(sudo:session): session closed for user root Feb 22 10:20:01 primo-plus volumio[977]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 10:20:01 primo-plus volumio[977]: TypeError: Cannot read property 'on' of undefined Feb 22 10:20:01 primo-plus volumio[977]: at /volumio/app/plugins/audio_interface/multiroom/multiroom_real:1:29834 Feb 22 10:20:01 primo-plus volumio[977]: at /volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/senders/platform.js:95:20 Feb 22 10:20:01 primo-plus volumio[977]: at /volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/receiver.js:51:14 Feb 22 10:20:01 primo-plus volumio[977]: at fn.onmessage (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/request-response.js:27:7) Feb 22 10:20:01 primo-plus volumio[977]: at fn.emit (events.js:327:22) Feb 22 10:20:01 primo-plus volumio[977]: at Channel.onmessage (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/controller.js:16:10) Feb 22 10:20:01 primo-plus volumio[977]: at Channel.emit (events.js:315:20) Feb 22 10:20:01 primo-plus volumio[977]: at Client.onmessage (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2/lib/channel.js:23:10) Feb 22 10:20:01 primo-plus volumio[977]: at Client.emit (events.js:327:22) Feb 22 10:20:01 primo-plus volumio[977]: at PacketStreamWrapper.onpacket (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2/lib/client.js:81:10) Feb 22 10:20:01 primo-plus volumio[977]: at PacketStreamWrapper.emit (events.js:315:20) Feb 22 10:20:01 primo-plus volumio[977]: at TLSSocket. (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2/lib/packet-stream-wrapper.js:28:16) Feb 22 10:20:01 primo-plus volumio[977]: at TLSSocket.emit (events.js:315:20) Feb 22 10:20:01 primo-plus volumio[977]: at emitReadable_ (internal/streams/readable.js:569:12) Feb 22 10:20:01 primo-plus volumio[977]: at processTicksAndRejections (internal/process/task_queues.js:79:21) Feb 22 10:20:01 primo-plus volumio[977]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 22 10:20:01 primo-plus sudo[6283]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Feb 22 10:20:01 primo-plus sudo[6283]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 10:20:01 primo-plus systemd[1]: Started VolumioStreamingService. Feb 22 10:20:01 primo-plus sudo[6283]: pam_unix(sudo:session): session closed for user root Feb 22 10:20:01 primo-plus sudo[6293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Feb 22 10:20:01 primo-plus sudo[6293]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 22 10:20:01 primo-plus sudo[6293]: pam_unix(sudo:session): session closed for user root Feb 22 10:20:01 primo-plus sudo[6298]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-22 10:19 Feb 22 10:20:01 primo-plus sudo[6298]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="primoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Feb 2026 04:01:29 PM CET" VOLUMIO_VERSION="3.908" VOLUMIO_HARDWARE="cm4" VOLUMIO_DEVICENAME="CM4" VOLUMIO_VENDOR_MODEL="Volumio Primo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo Plus" VOLUMIO_HASH="048051fc95e30092a9f7a83497492604"