Mar 28 14:09:00 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)... Mar 28 14:09:00 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:01 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::serviceStop Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::serviceStop Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::stPlaybackTimer Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["stop"],"request_id":27} Mar 28 14:09:01 volumio volumio[1476]: verbose: [rp2] Waiting for player event "stopped"... Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:09:01 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:01 volumio volumio[1476]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:09:01 volumio volumio[1476]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D5%22%2C%22name%22%3A%22Beyond...%22%2C%22title%22%3A%22Beyond...%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F5%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:09:01 volumio volumio[1476]: verbose: UNSET VOLATILE: Service: rp2 Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Volatile state unset, stopping playback (if any)... Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/26792.jpg","uri":"rp2/channel@id=3","seek":104093.41300000006,"duration":203.621,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"El Amor De Mis Amores","artist":"Acid Coco","album":"Mucho Gusto","trackType":"flac","samplerate":"The Globe"} Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:01 volumio volumio[1476]: verbose: STATE SERVICE {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/26792.jpg","uri":"rp2/channel@id=3","seek":104093.41300000006,"duration":203.621,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"El Amor De Mis Amores","artist":"Acid Coco","album":"Mucho Gusto","trackType":"flac","samplerate":"The Globe"} Mar 28 14:09:01 volumio volumio[1476]: verbose: CURRENT POSITION 0 Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::syncState stateService stop Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::syncState currentStatus stop Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:01 volumio volumio[1476]: info: No code Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:01 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:01.587+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 104093.41300000006 into Go struct field State.seek of type int" Mar 28 14:09:01 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:01.588+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 104093.41300000006 into Go struct field State.seek of type int" Mar 28 14:09:01 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:01.589+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 104093.41300000006 into Go struct field State.seek of type int" Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:01 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:09:01 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] clearAddPlayTrack: rp2/channel@id=5 Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #27: {"data":null,"request_id":27,"error":"success"} Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"},{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:09:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:09:02 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=5&audio_type= Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Obtained block for channel "5" Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Block summary Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/5/x/1656/4/b/1656-0.flac Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Tracks: Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] 0. Embrace (5:46 | elapsed: 15m 12s) Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] 1. Paean (5:17 | elapsed: 20m 59s) Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] 2. Body Roll (3:32 | elapsed: 26m 16s) Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:09:03 volumio volumio[1476]: verbose: [rp2] Current track scheduled playback vs. current time: 3/28/2026, 2:05:45 PM <-> 3/28/2026, 2:09:03 PM Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Going to start playback of current track at 3:18 (track position in stream: 15:12) Mar 28 14:09:03 volumio volumio[1476]: verbose: [rp2] Waiting for player event "playing"... Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:03 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Stopping playback by current service... Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioStop Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Setting ourselves as the current service... Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":28} Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #28: {"request_id":28,"error":"success"} Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","uri":"rp2/channel@id=5","seek":0,"duration":346.75,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","trackType":"flac","samplerate":"Beyond..."} Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/5/x/1656/4/b/1656-0.flac","replace","start=1110.868"],"request_id":29} Mar 28 14:09:03 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:03.374+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 346.75 into Go struct field State.duration of type int" Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #29: {"data":{"playlist_entry_id":5},"request_id":29,"error":"success"} Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"1656-0.flac"}] Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","pause",false],"request_id":30} Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=5","title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","trackType":"flac","duration":346.75,"samplerate":"Beyond...","service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:03 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:03.395+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 346.75 into Go struct field State.duration of type int" Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #30: {"request_id":30,"error":"success"} Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) (+) Audio --aid=1 (flac 2ch 44100Hz) Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1788.929002}] Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}] Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=5","title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","trackType":"flac","duration":346.75,"samplerate":"Beyond...","service":"rp2","seek":198343,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:03 volumio volumio[1476]: verbose: [rp2] Received player event "playing"... Mar 28 14:09:03 volumio volumio[1476]: info: [rp2] Started playback of "Embrace" - estimated finish time: 3/28/2026, 2:11:32 PM Mar 28 14:09:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:03 volumio volumio[1476]: verbose: [rp2] After "Embrace", the next track will start in 2m 28s (3/28/2026, 2:11:32 PM) Mar 28 14:09:03 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=55538&chan=5&player_id=********&event=126487&type=M&slice_num=4&episode_id=0&time_relative=-199&play_position_millis=198343&playtime_secs=1774703344 Mar 28 14:09:03 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:03.885+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 346.75 into Go struct field State.duration of type int" Mar 28 14:09:05 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)... Mar 28 14:09:05 volumio volumio[1476]: verbose: [rp2] Recalculated next track interval exceeds current by 2002ms. Going to re-adjust. Mar 28 14:09:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) AO: [alsa] 44100Hz stereo 2ch s16 Mar 28 14:09:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}] Mar 28 14:09:07 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=5","title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","trackType":"flac","duration":346.75,"samplerate":"44.1 kHz - Beyond...","bitdepth":"16-bit","channels":2,"service":"rp2","seek":198343,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:07 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:07 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:07 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:07 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:07 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:07.254+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 346.75 into Go struct field State.duration of type int" Mar 28 14:09:07 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:07 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)... Mar 28 14:09:07 volumio volumio[1476]: verbose: [rp2] Recalculated next track interval exceeds current by 1395.3950000000186ms. Going to re-adjust. Mar 28 14:09:09 volumio volumio[1476]: error: error Mar 28 14:09:09 volumio volumio[1476]: error: error Mar 28 14:09:09 volumio volumio[1476]: error: error Mar 28 14:09:09 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)... Mar 28 14:09:09 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:11 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)... Mar 28 14:09:11 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:13 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)... Mar 28 14:09:13 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:17 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::serviceStop Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::serviceStop Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::stPlaybackTimer Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["stop"],"request_id":31} Mar 28 14:09:17 volumio volumio[1476]: verbose: [rp2] Waiting for player event "stopped"... Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:09:17 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:17 volumio volumio[1476]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:09:17 volumio volumio[1476]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:09:17 volumio volumio[1476]: verbose: UNSET VOLATILE: Service: rp2 Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Volatile state unset, stopping playback (if any)... Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","uri":"rp2/channel@id=5","seek":208695.22699999996,"duration":346.75,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","trackType":"flac","samplerate":"Beyond..."} Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:17 volumio volumio[1476]: verbose: STATE SERVICE {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/24378.jpg","uri":"rp2/channel@id=5","seek":208695.22699999996,"duration":346.75,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Embrace","artist":"Levitation Orchestra","album":"Embrace","trackType":"flac","samplerate":"Beyond..."} Mar 28 14:09:17 volumio volumio[1476]: verbose: CURRENT POSITION 0 Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::syncState stateService stop Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::syncState currentStatus stop Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:17 volumio volumio[1476]: info: No code Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:17 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:17 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:17.688+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 208695.22699999996 into Go struct field State.seek of type int" Mar 28 14:09:17 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:17.689+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 208695.22699999996 into Go struct field State.seek of type int" Mar 28 14:09:17 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:17.690+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 208695.22699999996 into Go struct field State.seek of type int" Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:17 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:09:17 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] clearAddPlayTrack: rp2/channel@id=945 Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #31: {"data":null,"request_id":31,"error":"success"} Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"},{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:09:17 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:09:18 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:18 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:18 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:09:18 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:09:18 volumio volumio[1476]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:09:18 volumio volumio[1476]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D945%22%2C%22name%22%3A%22KFAT%22%2C%22title%22%3A%22KFAT%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F945%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:09:18 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:09:18 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:18 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:09:18 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:18 volumio volumio[1476]: info: [rp2] clearAddPlayTrack: rp2/channel@id=945 Mar 28 14:09:18 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:09:18 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=945&audio_type= Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=945&audio_type= Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Obtained block for channel "945" Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Block summary Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/945/x/1513/4/b/1513-0.flac Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Tracks: Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 0. Foggy Mountain Top (2:35 | elapsed: 13m 46s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 1. Cajun Girl featuring Little Feat & Sam Bush (3:50 | elapsed: 16m 21s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 2. Tulsa Queen (4:42 | elapsed: 20m 12s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 3. Trail Less Traveled (3:17 | elapsed: 24m 54s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 4. Sweet Summer Rain (3:40 | elapsed: 28m 11s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] Current track scheduled playback vs. current time: 3/28/2026, 2:09:03 PM <-> 3/28/2026, 2:09:19 PM Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Going to start playback of current track at 0:16 (track position in stream: 13:46) Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] Waiting for player event "playing"... Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:19 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Stopping playback by current service... Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioStop Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Setting ourselves as the current service... Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":32} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #32: {"request_id":32,"error":"success"} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","uri":"rp2/channel@id=945","seek":0,"duration":155.46,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","trackType":"flac","samplerate":"KFAT"} Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/945/x/1513/4/b/1513-0.flac","replace","start=842.898"],"request_id":33} Mar 28 14:09:19 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:19.569+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 155.46 into Go struct field State.duration of type int" Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #33: {"data":{"playlist_entry_id":6},"request_id":33,"error":"success"} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"1513-0.flac"}] Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","pause",false],"request_id":34} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=945","title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","trackType":"flac","duration":155.46,"samplerate":"KFAT","service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:19 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:19.579+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 155.46 into Go struct field State.duration of type int" Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #34: {"request_id":34,"error":"success"} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Obtained block for channel "945" Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Block summary Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/945/x/1513/4/b/1513-0.flac Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Tracks: Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 0. Foggy Mountain Top (2:35 | elapsed: 13m 46s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 1. Cajun Girl featuring Little Feat & Sam Bush (3:50 | elapsed: 16m 21s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 2. Tulsa Queen (4:42 | elapsed: 20m 12s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 3. Trail Less Traveled (3:17 | elapsed: 24m 54s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] 4. Sweet Summer Rain (3:40 | elapsed: 28m 11s) Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] Current track scheduled playback vs. current time: 3/28/2026, 2:09:03 PM <-> 3/28/2026, 2:09:19 PM Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] Going to start playback of current track at 0:16 (track position in stream: 13:46) Mar 28 14:09:19 volumio volumio[1476]: verbose: [rp2] Waiting for player event "playing"... Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":35} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #35: {"request_id":35,"error":"success"} Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","uri":"rp2/channel@id=945","seek":0,"duration":155.46,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","trackType":"flac","samplerate":"KFAT"} Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:19 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:19 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/945/x/1513/4/b/1513-0.flac","replace","start=843.329"],"request_id":36} Mar 28 14:09:19 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:19.998+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 155.46 into Go struct field State.duration of type int" Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #36: {"data":{"playlist_entry_id":7},"request_id":36,"error":"success"} Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","pause",false],"request_id":37} Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #37: {"request_id":37,"error":"success"} Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) (+) Audio --aid=1 (flac 2ch 44100Hz) Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1912.050998},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}] Mar 28 14:09:20 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:20 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=945","title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","trackType":"flac","duration":155.46,"samplerate":"KFAT","service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:20 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:20 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:20 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:20 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:20 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:20.546+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 155.46 into Go struct field State.duration of type int" Mar 28 14:09:26 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) AO: [alsa] 44100Hz stereo 2ch s16 Mar 28 14:09:26 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}] Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:26 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=945","title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","trackType":"flac","duration":155.46,"samplerate":"44.1 kHz - KFAT","bitdepth":"16-bit","channels":2,"service":"rp2","seek":16986,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:09:26 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] Received player event "playing"... Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] Received player event "playing"... Mar 28 14:09:26 volumio volumio[1476]: info: [rp2] Started playback of "Foggy Mountain Top" - estimated finish time: 3/28/2026, 2:11:45 PM Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] After "Foggy Mountain Top", the next track will start in 2m 18s (3/28/2026, 2:11:45 PM) Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=61232&chan=945&player_id=********&event=1684653&type=M&slice_num=4&episode_id=0&time_relative=-17&play_position_millis=16986&playtime_secs=1774703367 Mar 28 14:09:26 volumio volumio[1476]: info: [rp2] Started playback of "Foggy Mountain Top" - estimated finish time: 3/28/2026, 2:11:45 PM Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] After "Foggy Mountain Top", the next track will start in 2m 18s (3/28/2026, 2:11:45 PM) Mar 28 14:09:26 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=61232&chan=945&player_id=********&event=1684653&type=M&slice_num=4&episode_id=0&time_relative=-17&play_position_millis=16986&playtime_secs=1774703367 Mar 28 14:09:26 volumio volumio5-onboarding[1764]: time=2026-03-28T14:09:26.734+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 155.46 into Go struct field State.duration of type int" Mar 28 14:09:26 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:09:28 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)... Mar 28 14:09:28 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:30 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)... Mar 28 14:09:30 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:32 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)... Mar 28 14:09:32 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:34 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)... Mar 28 14:09:34 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:36 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)... Mar 28 14:09:36 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:09:51 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Mar 28 14:09:51 volumio volumio[1476]: verbose: [rp2] API: https://vsh-sdata.radioparadise.com/api/episodes?publicationState=live&populate=deep&pagination%5Bstart%5D=0&pagination%5Blimit%5D=41&sort%5B0%5D=release_num%3ADESC Mar 28 14:09:52 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Mar 28 14:09:56 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Mar 28 14:09:57 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Mar 28 14:09:57 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: rp2 , handleBrowseUri Mar 28 14:10:00 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::serviceStop Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::serviceStop Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::stPlaybackTimer Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["stop"],"request_id":38} Mar 28 14:10:00 volumio volumio[1476]: verbose: [rp2] Waiting for player event "stopped"... Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:10:00 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:00 volumio volumio[1476]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:10:00 volumio volumio[1476]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D in service rp2 Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:00 volumio bluealsa[960]: bluez.c:1290: Signal: org.freedesktop.DBus.ObjectManager.InterfacesAdded(/org/bluez/hci0/dev_67_61_45_27_01_EF, ...) Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:10:00 volumio volumio[1476]: verbose: UNSET VOLATILE: Service: rp2 Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Volatile state unset, stopping playback (if any)... Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","uri":"rp2/channel@id=945","seek":50809.19999999995,"duration":155.46,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","trackType":"flac","samplerate":"KFAT"} Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:00 volumio volumio[1476]: verbose: STATE SERVICE {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/27240.jpg","uri":"rp2/channel@id=945","seek":50809.19999999995,"duration":155.46,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Foggy Mountain Top","artist":"Carlene Carter","album":"Musical Shapes","trackType":"flac","samplerate":"KFAT"} Mar 28 14:10:00 volumio volumio[1476]: verbose: CURRENT POSITION 0 Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::syncState stateService stop Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::syncState currentStatus stop Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:00 volumio volumio[1476]: info: No code Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:00 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:00 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:00.654+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 50809.19999999995 into Go struct field State.seek of type int" Mar 28 14:10:00 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:00.657+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 50809.19999999995 into Go struct field State.seek of type int" Mar 28 14:10:00 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:00.658+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 50809.19999999995 into Go struct field State.seek of type int" Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:00 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:10:00 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] clearAddPlayTrack: rp2/channel@id=42 Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #38: {"data":null,"request_id":38,"error":"success"} Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"},{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:10:00 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:10:01 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:01 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:10:01 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:01 volumio volumio[1476]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:10:01 volumio volumio[1476]: info: Using cached record of: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D42%22%2C%22name%22%3A%22Serenity%22%2C%22title%22%3A%22Serenity%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F42%2Fcover_512x512%2F0.jpg%22%7D Mar 28 14:10:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:01 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:01 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:10:01 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:01 volumio volumio[1476]: info: [rp2] clearAddPlayTrack: rp2/channel@id=42 Mar 28 14:10:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:10:01 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:10:03 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=42&audio_type= Mar 28 14:10:03 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=42&audio_type= Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Obtained block for channel "42" Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Block summary Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/42/x/4244/4/b/4244-0.flac Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Tracks: Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] 0. AP Librae (14:43 | elapsed: 14m 41s) Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:10:03 volumio volumio[1476]: verbose: [rp2] Current track scheduled playback vs. current time: 3/28/2026, 2:04:38 PM <-> 3/28/2026, 2:10:03 PM Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] Going to start playback of current track at 5:25 (track position in stream: 14:41) Mar 28 14:10:03 volumio volumio[1476]: verbose: [rp2] Waiting for player event "playing"... Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:03 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Stopping playback by current service... Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::volumioStop Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Setting ourselves as the current service... Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":39} Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #39: {"request_id":39,"error":"success"} Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","uri":"rp2/channel@id=42","seek":0,"duration":883.375,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","trackType":"flac","samplerate":"Serenity"} Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/42/x/4244/4/b/4244-0.flac","replace","start=1206.566"],"request_id":40} Mar 28 14:10:03 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:03.818+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 883.375 into Go struct field State.duration of type int" Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #40: {"data":{"playlist_entry_id":8},"request_id":40,"error":"success"} Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"4244-0.flac"}] Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","pause",false],"request_id":41} Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=42","title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","trackType":"flac","duration":883.375,"samplerate":"Serenity","service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:03 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:03 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:03 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:03.829+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 883.375 into Go struct field State.duration of type int" Mar 28 14:10:03 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #41: {"request_id":41,"error":"success"} Mar 28 14:10:04 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:04 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:04 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:04 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:04 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Obtained block for channel "42" Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Block summary Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] ------------- Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/42/x/4244/4/b/4244-0.flac Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Tracks: Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] 0. AP Librae (14:43 | elapsed: 14m 41s) Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Mar 28 14:10:04 volumio volumio[1476]: verbose: [rp2] Current track scheduled playback vs. current time: 3/28/2026, 2:04:38 PM <-> 3/28/2026, 2:10:04 PM Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] Going to start playback of current track at 5:26 (track position in stream: 14:41) Mar 28 14:10:04 volumio volumio[1476]: verbose: [rp2] Waiting for player event "playing"... Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":42} Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #42: {"request_id":42,"error":"success"} Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","uri":"rp2/channel@id=42","seek":0,"duration":883.375,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","trackType":"flac","samplerate":"Serenity"} Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:04 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/42/x/4244/4/b/4244-0.flac","replace","start=1207.201"],"request_id":43} Mar 28 14:10:04 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:04.458+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 883.375 into Go struct field State.duration of type int" Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #43: {"data":{"playlist_entry_id":9},"request_id":43,"error":"success"} Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["set_property","pause",false],"request_id":44} Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #44: {"request_id":44,"error":"success"} Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) [lavf] avformat_open_input() failed Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) (+) Audio --aid=1 (flac 2ch 44100Hz) Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1764.457007},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}] Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:04 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=42","title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","trackType":"flac","duration":883.375,"samplerate":"Serenity","service":"rp2","seek":326119,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:04 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:04 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] Received player event "playing"... Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] Received player event "playing"... Mar 28 14:10:05 volumio volumio[1476]: info: [rp2] Started playback of "AP Librae" - estimated finish time: 3/28/2026, 2:19:22 PM Mar 28 14:10:05 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] After "AP Librae", prepare to fetch the next block in 9m 17s (3/28/2026, 2:19:22 PM) Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=46174&chan=42&player_id=********&event=22156&type=M&slice_num=1&episode_id=0&time_relative=-327&play_position_millis=326119&playtime_secs=1774703406 Mar 28 14:10:05 volumio volumio[1476]: info: [rp2] Started playback of "AP Librae" - estimated finish time: 3/28/2026, 2:19:22 PM Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] After "AP Librae", prepare to fetch the next block in 9m 17s (3/28/2026, 2:19:22 PM) Mar 28 14:10:05 volumio volumio[1476]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=46174&chan=42&player_id=********&event=22156&type=M&slice_num=1&episode_id=0&time_relative=-327&play_position_millis=326119&playtime_secs=1774703406 Mar 28 14:10:05 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:05.013+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 883.375 into Go struct field State.duration of type int" Mar 28 14:10:07 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)... Mar 28 14:10:07 volumio volumio[1476]: verbose: [rp2] Recalculated next track interval exceeds current by 2003ms. Going to re-adjust. Mar 28 14:10:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) AO: [alsa] 44100Hz stereo 2ch s16 Mar 28 14:10:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}] Mar 28 14:10:07 volumio volumio[1476]: info: CoreCommandRouter::volumioGetState Mar 28 14:10:07 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"play","uri":"rp2/channel@id=42","title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","trackType":"flac","duration":883.375,"samplerate":"44.1 kHz - Serenity","bitdepth":"16-bit","channels":2,"service":"rp2","seek":326119,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true} Mar 28 14:10:07 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:07 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:07 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:07 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:07 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:07.039+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 883.375 into Go struct field State.duration of type int" Mar 28 14:10:08 volumio volumio[1476]: error: error Mar 28 14:10:08 volumio volumio[1476]: error: error Mar 28 14:10:08 volumio volumio[1476]: error: error Mar 28 14:10:09 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)... Mar 28 14:10:09 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:10:11 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)... Mar 28 14:10:11 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:10:13 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)... Mar 28 14:10:13 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:10:15 volumio volumio[1476]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)... Mar 28 14:10:15 volumio volumio[1476]: verbose: [rp2] Next track interval is accurate Mar 28 14:10:30 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: motherearthradio , handleBrowseUri Mar 28 14:10:30 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:34 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::serviceStop Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::serviceStop Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::stPlaybackTimer Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Send IPC command: {"command":["stop"],"request_id":45} Mar 28 14:10:34 volumio volumio[1476]: verbose: [rp2] Waiting for player event "stopped"... Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:10:34 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:34 volumio volumio[1476]: info: Adding Item to queue: motherearthradio/radio/flac192 Mar 28 14:10:34 volumio volumio[1476]: info: Using cached record of: motherearthradio/radio/flac192 Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:10:34 volumio volumio[1476]: verbose: UNSET VOLATILE: Service: rp2 Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Volatile state unset, stopping playback (if any)... Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/19352.jpg","uri":"rp2/channel@id=42","seek":353773.601,"duration":883.375,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"AP Librae","artist":"Rule 42","album":"Ambient Explorations 12","trackType":"flac","samplerate":"Serenity"} Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:34 volumio volumio[1476]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current motherearthradio Received rp2 Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:34 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:34.760+01:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 353773.601 into Go struct field State.seek of type int" Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:34 volumio volumio[1476]: info: [MER] ▶️ Playing: https://stream.motherearthradio.de/listen/motherearth/motherearth Mar 28 14:10:34 volumio volumio[1476]: info: [MER] 🔌 Starting SSE for Radio Mar 28 14:10:34 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Got response for command #45: {"data":null,"request_id":45,"error":"success"} Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"},{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - unsetting ourselves as current service... Mar 28 14:10:34 volumio volumio[1476]: verbose: [rp2] Received player event "stopped"... Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 28 14:10:34 volumio volumio[1476]: info: [rp2] [mpv] (PID: 2733) Mar 28 14:10:34 volumio volumio[1476]: info: sendMpdCommand stop took 9 milliseconds Mar 28 14:10:34 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand clear Mar 28 14:10:34 volumio volumio[1476]: info: sendMpdCommand clear took 0 milliseconds Mar 28 14:10:34 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand add "https://stream.motherearthradio.de/listen/motherearth/motherearth" Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: sendMpdCommand add "https://stream.motherearthradio.de/listen/motherearth/motherearth" took 4 milliseconds Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 4ms Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 3ms Mar 28 14:10:34 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand play Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: Mar 28 14:10:34 volumio volumio[1476]: ---------------------------- MPD announces system playlist update Mar 28 14:10:34 volumio volumio[1476]: info: Ignoring MPD Status Update Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 9ms Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 9ms Mar 28 14:10:34 volumio volumio[1476]: info: sendMpdCommand play took 4 milliseconds Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 4ms Mar 28 14:10:34 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:34 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:34 volumio volumio[1476]: verbose: STATE SERVICE {"status":"play","service":"motherearthradio","type":"webradio","trackType":"flac","radioType":"mer","title":"Connecting...","artist":"Mother Earth Radio","album":"Radio · FLAC 192kHz/24bit Stereo","albumart":"/albumart?sourceicon=music_service/motherearthradio/mer-logo-cube-bold-1x 512.png","uri":"motherearthradio/radio/flac192","streaming":true,"disableUiControls":true,"samplerate":"192 kHz","bitdepth":"24 bit","duration":0,"seek":0} Mar 28 14:10:34 volumio volumio[1476]: verbose: CURRENT POSITION 0 Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::syncState stateService play Mar 28 14:10:34 volumio volumio[1476]: info: CoreStateMachine::syncState currentStatus stop Mar 28 14:10:34 volumio volumio[1476]: info: ------------------------------ 6ms Mar 28 14:10:35 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::ClearQueue Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::stPlaybackTimer Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::serviceStop Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::serviceStop Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::servicePushState Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: verbose: STATE SERVICE {"status":"stop","service":"motherearthradio"} Mar 28 14:10:35 volumio volumio[1476]: verbose: CURRENT POSITION 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::syncState stateService stop Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::syncState currentStatus stop Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:35 volumio volumio[1476]: info: No code Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::pushState Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushState Mar 28 14:10:35 volumio volumio[1476]: info: ControllerMpd::stop Mar 28 14:10:35 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::clearPlayQueue Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::addQueueItems Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::addQueueItems Mar 28 14:10:35 volumio volumio[1476]: info: Preload queue cleared Mar 28 14:10:35 volumio volumio[1476]: info: Adding Item to queue: motherearthradio/radio/flac192 Mar 28 14:10:35 volumio volumio[1476]: info: Using cached record of: motherearthradio/radio/flac192 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.658+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.659+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.659+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.659+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.661+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.661+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.661+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.661+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.662+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.663+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.663+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.663+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.665+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.666+01:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" state=STATUS_STOPPED positionMs=0 volume=100 Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.666+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.147:50837 @ 0x2800c90" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio5-onboarding[1764]: time=2026-03-28T14:10:35.666+01:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.178.96:45294 @ 0x2b1aa50" id=motherearthradio/radio/flac192 title=Radio Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPushQueue Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::saveQueue Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::updateTrackBlock Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrackBlock Mar 28 14:10:35 volumio volumio[1476]: info: CoreCommandRouter::volumioPlay Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::play index 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::stop Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::play index undefined Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: CoreStateMachine::startPlaybackTimer Mar 28 14:10:35 volumio volumio[1476]: info: CorePlayQueue::getTrack 0 Mar 28 14:10:35 volumio volumio[1476]: info: [MER] ▶️ Playing: https://stream.motherearthradio.de/listen/motherearth/motherearth Mar 28 14:10:35 volumio volumio[1476]: info: [MER] 🔌 Starting SSE for Radio Mar 28 14:10:35 volumio volumio[1476]: verbose: ControllerMpd::sendMpdCommand stop Mar 28 14:10:35 volumio volumio[1476]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 14:10:35 volumio volumio[1476]: Error: socket hang up Mar 28 14:10:35 volumio volumio[1476]: at connResetException (node:internal/errors:720:14) Mar 28 14:10:35 volumio volumio[1476]: at TLSSocket.socketCloseListener (node:_http_client:468:25) Mar 28 14:10:35 volumio volumio[1476]: at TLSSocket.emit (node:events:526:35) Mar 28 14:10:35 volumio volumio[1476]: at node:net:337:12 Mar 28 14:10:35 volumio volumio[1476]: at TCP.done (node:_tls_wrap:631:7) { Mar 28 14:10:35 volumio volumio[1476]: code: 'ECONNRESET' Mar 28 14:10:35 volumio volumio[1476]: } Mar 28 14:10:35 volumio volumio[1476]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 28 14:10:36 volumio sudo[3175]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 14:09' Mar 28 14:10:36 volumio sudo[3175]: 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="dc61260dec5515dafd2b634881860b4c46c919ff" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026" VOLUMIO_VERSION="4.103" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"