Aug 25 13:17:03 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:03.751: playing spotify:track:1Mys1gf9SkMBAVGGxpkJ7d "Reality" by "Lost Frequencies" [2:29 / 2:39] Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.331+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.331+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.331+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.331+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.332+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: touch_display: Setting screensaver timeout to 0 seconds. Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=159000 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.368+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.369+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.369+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:1Mys1gf9SkMBAVGGxpkJ7d title=Reality Aug 25 13:17:13 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:13.422: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:00 / 3:11] Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.433+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.433+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.434+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.435+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.435+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.435+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.435+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.442+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.442+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.442+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.442+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.442+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.443+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.443+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.443+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=5 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=5 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=5 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=5 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.823+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.824+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=6 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.824+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=6 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.825+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.825+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.849+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=84 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.849+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=84 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.849+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.849+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:17:13 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.897+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=91 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.898+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=91 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.898+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.898+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.899+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=91 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.899+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=91 volume=47 Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.899+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:13 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:17:13.899+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:17:23 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:23.751: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:09 / 3:11] Aug 25 13:17:33 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:33.750: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:19 / 3:11] Aug 25 13:17:43 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:43.751: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:29 / 3:11] Aug 25 13:17:53 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:17:53.750: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:39 / 3:11] Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.443+02:00 level=INFO msg="check connectivity" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.509+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=http://pushupdates.volumio.org duration=66.127065ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.577+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://radio-directory.firebaseapp.com duration=134.427717ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.611+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://oauth-performer.dfs.volumio.org duration=168.213834ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.617+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://browsing-performer.dfs.volumio.org duration=174.013772ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.633+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://google.com duration=190.076654ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.646+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://www.googleapis.com duration=202.994033ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.649+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://securetoken.googleapis.com duration=205.378711ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.718+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://functions.volumio.cloud duration=273.807973ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.718+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://functions.volumio.cloud duration=273.707697ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.773+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://myvolumio.firebaseio.com duration=329.073173ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.878+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=https://database.volumio.cloud duration=434.808052ms Aug 25 13:18:02 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:02.890+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=http://cddb.volumio.org duration=446.530814ms Aug 25 13:18:03 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:03.016+02:00 level=INFO msg="endpoint is reachable" component=server type=REQUEST_TYPE_CHECK_INTERNET_CONNECTIVITY peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" latency=83.013793ms timeout=10s endpoint=http://plugins.volumio.org duration=571.661169ms Aug 25 13:18:03 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:18:03.751: playing spotify:track:709ta4BqbSzXxWZZ2VShrg "My Mouth (la la la)" by "ISHAN" [0:49 / 3:11] Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:04 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:04 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:04.773+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=50979 volume=47 Aug 25 13:18:04 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:04.773+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=50979 volume=47 Aug 25 13:18:04 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:04.773+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:18:04 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:04.773+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.767+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.767+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.767+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.767+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:709ta4BqbSzXxWZZ2VShrg title="My Mouth (la la la)" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.774+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.774+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.774+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id= title= Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.774+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id= title= Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.774+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.779+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=52973 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.779+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id= title= Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.779+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id= title= Aug 25 13:18:06 es9038q2m-volumio start-soloist.sh[1445]: 2026-08-25 13:18:06.826: playing spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 "Big Bad John" by "Geoff Castellucci" [0:00 / 3:56] Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.836+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.837+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.838+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.838+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.838+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.838+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.880+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.880+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.880+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.880+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.882+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.882+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.883+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.884+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.884+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=0 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.884+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.884+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: touch_display: Setting screensaver timeout to 0 seconds. Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.941+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=23 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.941+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=23 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.942+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.942+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CorePlayQueue::getTrack 15 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spotify_soloist Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.970+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_STOPPED positionMs=1462 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.970+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_STOPPED positionMs=1462 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.970+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.970+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist command: get_state Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:06 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.985+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2027 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.985+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2027 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.985+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2027 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.985+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.985+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.986+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2027 volume=47 Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.986+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:06 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:06.986+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: Spotify Soloist: Spotify -> Volumio exact volume: 47 Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::servicePushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreStateMachine::pushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioPushState Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output update for this device Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: MRS: Pushing multiroomSync output Aug 25 13:18:07 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::volumioGetState Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2029 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2029 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2053 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2056 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2056 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" state=STATUS_PLAYING positionMs=2056 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2053 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" state=STATUS_PLAYING positionMs=2056 volume=47 Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="00:00:00:00:00:00%02,192.168.0.175:57384 @ 0x1bf0840" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:07 es9038q2m-volumio volumio5-onboarding[1655]: time=2026-08-25T13:18:07.029+02:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.0.175:57384 @ 0x1c44750" id=spotify:track:0ZwFAzKgF9ehHKnZeI1lD2 title="Big Bad John" Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: info: CoreCommandRouter::executeOnPlugin: spotify_soloist , alsavolume Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: TypeError: self.getVolumeStep is not a function Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at ControllerSpotifySoloist.alsavolume (/data/plugins/music_service/spotify_soloist/index.js:1487:28) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at CoreVolumeController.alsavolume (/volumio/app/volumecontrol.js:338:31) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at CoreCommandRouter.volumiosetvolume (/volumio/app/index.js:135:35) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:304:33) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at Socket.emit (node:events:514:28) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Aug 25 13:18:08 es9038q2m-volumio volumio[1443]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 25 13:18:08 es9038q2m-volumio sudo[10549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-08-25 13:17' Aug 25 13:18:08 es9038q2m-volumio sudo[10549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"