Mar 04 12:19:02 volumio volumio[1301]: info: Preload queue cleared
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::ClearQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::updateTrackBlock
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrackBlock
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::serviceStop
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::serviceStop
Mar 04 12:19:02 volumio volumio[1301]: info: [1772619542126] ControllerWebradio::stop
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand stop
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::clearPlayQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::saveQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::addQueueItems
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::addQueueItems
Mar 04 12:19:02 volumio volumio[1301]: info: Preload queue cleared
Mar 04 12:19:02 volumio volumio[1301]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D
Mar 04 12:19:02 volumio volumio[1301]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D0%22%2C%22name%22%3A%22The%20Main%20Mix%22%2C%22title%22%3A%22The%20Main%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F0%2Fcover_512x512%2F0.jpg%22%7D in service rp2
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::saveQueue
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::updateTrackBlock
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrackBlock
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPlay
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::play index 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::play index undefined
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::startPlaybackTimer
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: [rp2] clearAddPlayTrack: rp2/channel@id=0
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- Volumio status=stop timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:02 volumio volumio[1301]: info:
Mar 04 12:19:02 volumio volumio[1301]: ---------------------------- MPD announces state update: player
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand stop took 21 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::getState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status
Mar 04 12:19:02 volumio volumio[1301]: info:
Mar 04 12:19:02 volumio volumio[1301]: ---------------------------- MPD announces state update: player
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::getState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status
Mar 04 12:19:02 volumio volumio[1301]: info:
Mar 04 12:19:02 volumio volumio[1301]: ---------------------------- MPD announces state update: player
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::getState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status
Mar 04 12:19:02 volumio volumio[1301]: info:
Mar 04 12:19:02 volumio volumio[1301]: ---------------------------- MPD announces state update: player
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::getState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand status
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand status took 2 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand status took 2 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand status took 1 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand status took 1 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseState
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo
Mar 04 12:19:02 volumio volumio[1301]: verbose: ControllerMpd::parseTrackInfo
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current rp2 Received mpd
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current rp2 Received mpd
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current rp2 Received mpd
Mar 04 12:19:02 volumio volumio[1301]: info: ControllerMpd::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:02 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:02 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:02 volumio volumio[1301]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current rp2 Received mpd
Mar 04 12:19:02 volumio volumio[1301]: info: ------------------------------ 14ms
Mar 04 12:19:02 volumio volumio[1301]: info: ------------------------------ 13ms
Mar 04 12:19:02 volumio volumio[1301]: info: ------------------------------ 12ms
Mar 04 12:19:02 volumio volumio[1301]: info: ------------------------------ 12ms
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:02 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- Volumio status=stop timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- Volumio status=stop timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- Volumio status=stop timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- Volumio status=stop timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:02 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:02 volumio volumio[1301]: info: camilladsp respawn in 100 ms (attempt 1/10)
Mar 04 12:19:02 volumio volumio[1301]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=0&audio_type=
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Obtained block for channel "0"
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] -------------
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Block summary
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] -------------
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/0/x/1485/4/b/1485-0.flac
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Tracks:
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] 0. Listen Here (7:30 | elapsed: 16m 16s)
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] 1. Mystery Babylon (3:24 | elapsed: 23m 46s)
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2]
Mar 04 12:19:03 volumio volumio[1301]: verbose: [rp2] Current track scheduled playback vs. current time: 3/4/2026, 12:15:45 PM <-> 3/4/2026, 12:19:03 PM
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Going to start playback of current track at 3:18 (track position in stream: 16:16)
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] Starting mpv
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] [mpv] mpv version: 0.35.1
Mar 04 12:19:03 volumio volumio[1301]: info: [rp2] [mpv] mpv process spawned
Mar 04 12:19:03 volumio volumio[1301]: verbose: [rp2] Waiting for player event "playing"...
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Started (IPC socket: /tmp/volumio_mpv_socket_8ef439d3-52b5-4fb1-9877-83be6b25afca)
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",1,"pause"],"request_id":0}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",2,"duration"],"request_id":1}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",3,"idle-active"],"request_id":2}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",4,"volume"],"request_id":3}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",5,"mute"],"request_id":4}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",6,"audio-params"],"request_id":5}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",7,"audio-codec-name"],"request_id":6}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",8,"media-title"],"request_id":7}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",9,"metadata"],"request_id":8}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",10,"time-pos"],"request_id":9}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",11,"playback-restart"],"request_id":10}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["observe_property",12,"seeking"],"request_id":11}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #0: {"request_id":0,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #1: {"request_id":1,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #2: {"request_id":2,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #3: {"request_id":3,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #4: {"request_id":4,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #5: {"request_id":5,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #6: {"request_id":6,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #7: {"request_id":7,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #8: {"request_id":8,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #9: {"request_id":9,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #10: {"request_id":10,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #11: {"request_id":11,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":1,"prop":"pause","data":false},{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":4,"prop":"volume","data":100},{"subscriptionId":5,"prop":"mute","data":false},{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}]
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Player status "stopped" - skip unset volatile because unset condition is "manual"
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:04 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Stopping playback by current service...
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioStop
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Setting ourselves as the current service...
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":12}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #12: {"request_id":12,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","uri":"rp2/channel@id=0","seek":0,"duration":450.203,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","trackType":"flac"}
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/0/x/1485/4/b/1485-0.flac","replace","start=1175"],"request_id":13}
Mar 04 12:19:04 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:04.124+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 450.203 into Go struct field State.duration of type int"
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #13: {"data":{"playlist_entry_id":1},"request_id":13,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"1485-0.flac"}]
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["set_property","pause",false],"request_id":14}
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"play","uri":"rp2/channel@id=0","title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","trackType":"flac","duration":450.203,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true}
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:04 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:04.128+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 450.203 into Go struct field State.duration of type int"
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:04 volumio volumio[1301]: warn: FusionDsp - Monitor WebSocket not open, skipping commands
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- Volumio status=pause timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #14: {"request_id":14,"error":"success"}
Mar 04 12:19:04 volumio volumio[1301]: error: FusionDsp - Monitor WebSocket error: [object Object]
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 2000ms
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) (+) Audio --aid=1 (flac 2ch 44100Hz)
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1630.912993},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"}]
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":9,"prop":"metadata","data":{}}]
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"play","uri":"rp2/channel@id=0","title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","trackType":"flac","duration":450.203,"service":"rp2","seek":198485,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true}
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:04 volumio volumio[1301]: verbose: [rp2] Received player event "playing"...
Mar 04 12:19:04 volumio volumio[1301]: info: [rp2] Started playback of "Listen Here" - estimated finish time: 3/4/2026, 12:23:16 PM
Mar 04 12:19:04 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:04 volumio volumio[1301]: verbose: [rp2] After "Listen Here", the next track will start in 4m 11s (3/4/2026, 12:23:16 PM)
Mar 04 12:19:04 volumio volumio[1301]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=36946&chan=0&player_id=********&event=2845918&type=M&slice_num=4&episode_id=0&time_relative=-199&play_position_millis=198485&playtime_secs=1772619545
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:04 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:04.856+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 450.203 into Go struct field State.duration of type int"
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:04 volumio volumio[1301]: error: FusionDsp - Monitor WebSocket error: [object Object]
Mar 04 12:19:04 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 4000ms
Mar 04 12:19:04 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:06 volumio volumio[1301]: error: FusionDsp - Monitor WebSocket error: [object Object]
Mar 04 12:19:06 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 8000ms
Mar 04 12:19:06 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)...
Mar 04 12:19:06 volumio volumio[1301]: verbose: [rp2] Recalculated next track interval exceeds current by 2001ms. Going to re-adjust.
Mar 04 12:19:07 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) AO: [alsa] 44100Hz stereo 2ch s16
Mar 04 12:19:07 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}]
Mar 04 12:19:07 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:07 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"play","uri":"rp2/channel@id=0","title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","trackType":"flac","duration":450.203,"samplerate":"44.1 kHz","bitdepth":"16-bit","channels":2,"service":"rp2","seek":198485,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true}
Mar 04 12:19:07 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:07 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:07 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:07 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:07 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:07.968+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 450.203 into Go struct field State.duration of type int"
Mar 04 12:19:07 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:07 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:07 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:07 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:07 volumio volumio[1301]: info: FusionDsp - Clipping Monitor started
Mar 04 12:19:07 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:08 volumio volumio[1301]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Mar 04 12:19:08 volumio volumio[1301]: info: FusionDsp - ---- read samplerate from file: 44100
Mar 04 12:19:08 volumio volumio[1301]: info: camilladsp stopping service pid 49763...
Mar 04 12:19:08 volumio volumio[1301]: grep: /proc/49763/cmdline: binary file matches
Mar 04 12:19:08 volumio volumio[1301]: grep: /proc/49763/cmdline: binary file matches
Mar 04 12:19:08 volumio volumio[1301]: grep: /proc/49763/cmdline: binary file matches
Mar 04 12:19:08 volumio volumio[1301]: grep: /proc/49763/cmdline: binary file matches
Mar 04 12:19:08 volumio volumio[1301]: grep: /proc/49763/cmdline: binary file matches
Mar 04 12:19:08 volumio volumio[1301]: info: camilladsp service terminated, instance 1
Mar 04 12:19:08 volumio volumio[1301]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Mar 04 12:19:08 volumio volumio[1301]: info: camilladsp service started and running in background, instance 1
Mar 04 12:19:08 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 16000ms
Mar 04 12:19:08 volumio volumio[1301]: info: camilladsp respawn in 100 ms (attempt 1/10)
Mar 04 12:19:08 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)...
Mar 04 12:19:08 volumio volumio[1301]: verbose: [rp2] Recalculated next track interval exceeds current by 681.8619999999646ms. Going to re-adjust.
Mar 04 12:19:08 volumio volumio[1301]: info: FusionDsp - Clipping Monitor started
Mar 04 12:19:10 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)...
Mar 04 12:19:10 volumio volumio[1301]: verbose: [rp2] Recalculated next track interval exceeds current by 647.0300605467055ms. Going to re-adjust.
Mar 04 12:19:12 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)...
Mar 04 12:19:12 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:19:14 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)...
Mar 04 12:19:14 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:19:27 volumio volumio[1301]: info: Preload queue cleared
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::ClearQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::serviceStop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::serviceStop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::stPlaybackTimer
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::updateTrackBlock
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::getTrackBlock
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["stop"],"request_id":15}
Mar 04 12:19:27 volumio volumio[1301]: verbose: [rp2] Waiting for player event "stopped"...
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::clearPlayQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::saveQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPushQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::addQueueItems
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::addQueueItems
Mar 04 12:19:27 volumio volumio[1301]: info: Preload queue cleared
Mar 04 12:19:27 volumio volumio[1301]: info: Adding Item to queue: rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D
Mar 04 12:19:27 volumio volumio[1301]: info: Exploding uri rp2/channel@qi=%7B%22service%22%3A%22rp2%22%2C%22uri%22%3A%22rp2%2Fchannel%40id%3D1%22%2C%22name%22%3A%22Mellow%20Mix%22%2C%22title%22%3A%22Mellow%20Mix%22%2C%22artist%22%3A%22Radio%20Paradise%22%2C%22albumart%22%3A%22https%3A%2F%2Fimg.radioparadise.com%2Fchannels%2F0%2F1%2Fcover_512x512%2F0.jpg%22%7D in service rp2
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPushQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::saveQueue
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::updateTrackBlock
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::getTrackBlock
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPlay
Mar 04 12:19:27 volumio volumio[1301]: verbose: UNSET VOLATILE: Service: rp2
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Volatile state unset, stopping playback (if any)...
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","uri":"rp2/channel@id=0","seek":219218.55999999982,"duration":450.203,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","trackType":"flac"}
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:27 volumio volumio[1301]: verbose: STATE SERVICE {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/9184.jpg","uri":"rp2/channel@id=0","seek":219218.55999999982,"duration":450.203,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"Listen Here","artist":"Eddie Harris","album":"The Electrifying Eddie Harris","trackType":"flac"}
Mar 04 12:19:27 volumio volumio[1301]: verbose: CURRENT POSITION 0
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::syncState stateService stop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::syncState currentStatus stop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:27 volumio volumio[1301]: info: No code
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:27 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::play index 0
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:27 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:27.634+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 219218.55999999982 into Go struct field State.seek of type int"
Mar 04 12:19:27 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:27.634+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 219218.55999999982 into Go struct field State.seek of type int"
Mar 04 12:19:27 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:27.634+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 219218.55999999982 into Go struct field State.seek of type int"
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::play index undefined
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:27 volumio volumio[1301]: info: CoreStateMachine::startPlaybackTimer
Mar 04 12:19:27 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] clearAddPlayTrack: rp2/channel@id=1
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #15: {"data":null,"request_id":15,"error":"success"}
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) 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 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Player status "stopped" - unsetting ourselves as current service...
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Player status "stopped" - unsetting ourselves as current service...
Mar 04 12:19:27 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:27 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:27 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:27 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770)
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:27 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:28 volumio volumio[1301]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=0&elapsed=0&bitrate=4&action=start&player_id=********&info=true&chan=1&audio_type=
Mar 04 12:19:28 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms
Mar 04 12:19:28 volumio volumio[1301]: info: camilladsp respawn in 200 ms (attempt 2/10)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] Obtained block for channel "1"
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] -------------
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] Block summary
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] -------------
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/1/x/1609/4/b/1609-0.flac
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] Tracks:
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] 0. The Path of Thorns (Terms) (5:31 | elapsed: 13m 10s)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] 1. Urge For Going (5:44 | elapsed: 18m 42s)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] 2. Up From the Skies (3:38 | elapsed: 24m 26s)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] 3. The Good, The Bad & The Ugly (2:37 | elapsed: 28m 5s)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2]
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Player status "stopped" - skip unset volatile because unset condition is "manual"
Mar 04 12:19:29 volumio volumio[1301]: verbose: [rp2] Current track scheduled playback vs. current time: 3/4/2026, 12:16:24 PM <-> 3/4/2026, 12:19:29 PM
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] Going to start playback of current track at 3:05 (track position in stream: 13:10)
Mar 04 12:19:29 volumio volumio[1301]: verbose: [rp2] Waiting for player event "playing"...
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:29 volumio volumio[1301]: info: CorePlayQueue::getTrack 0
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Stopping playback by current service...
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioStop
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::stop
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Setting ourselves as the current service...
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":16}
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #16: {"request_id":16,"error":"success"}
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/12781.jpg","uri":"rp2/channel@id=1","seek":0,"duration":331.5,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true,"title":"The Path of Thorns (Terms)","artist":"Sarah McLachlan","album":"Solace","trackType":"flac"}
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/1/x/1609/4/b/1609-0.flac","replace","start=975.842"],"request_id":17}
Mar 04 12:19:29 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:29.312+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 331.5 into Go struct field State.duration of type int"
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #17: {"data":{"playlist_entry_id":2},"request_id":17,"error":"success"}
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"1609-0.flac"}]
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Send IPC command: {"command":["set_property","pause",false],"request_id":18}
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"play","uri":"rp2/channel@id=1","title":"The Path of Thorns (Terms)","artist":"Sarah McLachlan","album":"Solace","albumart":"https://img.radioparadise.com/covers/l/12781.jpg","trackType":"flac","duration":331.5,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true}
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:29 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:29 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:29.315+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 331.5 into Go struct field State.duration of type int"
Mar 04 12:19:29 volumio volumio[1301]: info: FusionDsp - Volumio is not playing
Mar 04 12:19:29 volumio volumio[1301]: info: FusionDsp - Clipped samples monitor stopped
Mar 04 12:19:29 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:29 volumio volumio[1301]: warn: FusionDsp - Monitor WebSocket not open, skipping commands
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- Volumio status=pause timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Got response for command #18: {"request_id":18,"error":"success"}
Mar 04 12:19:29 volumio volumio[1301]: error: FusionDsp - Monitor WebSocket error: [object Object]
Mar 04 12:19:29 volumio volumio[1301]: info: FusionDsp - Clipping Monitor reconnecting in 30000ms
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:29 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) (+) Audio --aid=1 (flac 2ch 44100Hz)
Mar 04 12:19:29 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1842.656009},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}]
Mar 04 12:19:29 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:35 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) AO: [alsa] 44100Hz stereo 2ch s16
Mar 04 12:19:35 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}]
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:35 volumio volumio[1301]: info: [rp2] [mpv] (PID: 49770) Push Volumio state: {"status":"play","uri":"rp2/channel@id=1","title":"The Path of Thorns (Terms)","artist":"Sarah McLachlan","album":"Solace","albumart":"https://img.radioparadise.com/covers/l/12781.jpg","trackType":"flac","duration":331.5,"samplerate":"44.1 kHz","bitdepth":"16-bit","channels":2,"service":"rp2","seek":185042,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":true}
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::servicePushState
Mar 04 12:19:35 volumio volumio[1301]: info: CoreStateMachine::pushState
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::volumioPushState
Mar 04 12:19:35 volumio volumio[1301]: verbose: [rp2] Received player event "playing"...
Mar 04 12:19:35 volumio volumio[1301]: info: [rp2] Started playback of "The Path of Thorns (Terms)" - estimated finish time: 3/4/2026, 12:22:01 PM
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:35 volumio volumio[1301]: verbose: [rp2] After "The Path of Thorns (Terms)", the next track will start in 2m 26s (3/4/2026, 12:22:01 PM)
Mar 04 12:19:35 volumio volumio[1301]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=34716&chan=1&player_id=********&event=2855574&type=M&slice_num=3&episode_id=0&time_relative=-186&play_position_millis=185042&playtime_secs=1772619576
Mar 04 12:19:35 volumio volumio5-onboarding[1751]: time=2026-03-04T12:19:35.254+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 331.5 into Go struct field State.duration of type int"
Mar 04 12:19:35 volumio volumio[1301]: info: CoreCommandRouter::volumioGetState
Mar 04 12:19:35 volumio volumio[1301]: info: FusionDsp - Volumio is playing
Mar 04 12:19:35 volumio volumio[1301]: info: Display-configuration --- Volumio status=play timeout=0 noifplay=true screensavertype=dpms
Mar 04 12:19:35 volumio volumio[1301]: info: Display-configuration --- → Wakeup triggered
Mar 04 12:19:35 volumio volumio[1301]: info: FusionDsp - Clipping Monitor started
Mar 04 12:19:35 volumio volumio[1301]: info: Display-configuration --- wakeupScreen: DPMS - screen on
Mar 04 12:19:35 volumio volumio[1301]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Mar 04 12:19:35 volumio volumio[1301]: info: FusionDsp - ---- read samplerate from file: 44100
Mar 04 12:19:35 volumio volumio[1301]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Mar 04 12:19:37 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)...
Mar 04 12:19:37 volumio volumio[1301]: verbose: [rp2] Recalculated next track interval exceeds current by 871.6510000000708ms. Going to re-adjust.
Mar 04 12:19:39 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)...
Mar 04 12:19:39 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:19:41 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)...
Mar 04 12:19:41 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:19:43 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)...
Mar 04 12:19:43 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:19:45 volumio volumio[1301]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)...
Mar 04 12:19:45 volumio volumio[1301]: verbose: [rp2] Next track interval is accurate
Mar 04 12:20:10 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Mar 04 12:20:11 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Mar 04 12:20:11 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Mar 04 12:20:33 volumio volumio[1301]: info: [1772619633161] [80s80s] Pushing the next song state Kim Wilde - View From a Bridge and getting next track.
Mar 04 12:20:33 volumio volumio[1301]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 12:20:33 volumio volumio[1301]: TypeError: Cannot set properties of undefined (setting 'name')
Mar 04 12:20:33 volumio volumio[1301]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20)
Mar 04 12:20:33 volumio volumio[1301]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34)
Mar 04 12:20:33 volumio volumio[1301]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9)
Mar 04 12:20:33 volumio volumio[1301]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66)
Mar 04 12:20:33 volumio volumio[1301]: at process.processImmediate (node:internal/timers:478:21)
Mar 04 12:20:33 volumio volumio[1301]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 04 12:20:33 volumio sudo[50116]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-04 12:19'
Mar 04 12:20:33 volumio sudo[50116]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Feb 5 14:31:57 UTC 2026"
VOLUMIO_VERSION="4.096"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="6759e875c98b942866984e844891d6c1"