Mar 24 17:06:24 volumio-pi4 volumio[12879]: info: [rp2] About to reach end of stream in current block. Going to obtain next block. Mar 24 17:06:24 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player to stop before fetching next block... Mar 24 17:06:24 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "stopped"... Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":7,"prop":"audio-codec-name"}] Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"play","uri":"rp2/channel@id=2","title":"The Walk (Everything Mix)","artist":"The Cure","album":"Let's Go to Bed EP","albumart":"https://img.radioparadise.com/covers/l/7668.jpg","trackType":"RockIt!","duration":327.867,"service":"rp2","seek":327501.59899999993,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:26 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:27 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "stopped"... Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:27 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=2765148&elapsed=1&bitrate=4&action=play&player_id=********&info=true&chan=2&slice_num=5&episode_id=0&audio_type=M Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Obtained updated block Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] ------------- Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Block summary Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] ------------- Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/promos/2/4/228.flac?2765149 Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Tracks: Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] 0. Listener-supported (0:02 | elapsed: 0s) Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Going to start playback of current track Mar 24 17:06:27 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "playing"... Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":39} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #39: {"request_id":39,"error":"success"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/103.jpg","uri":"rp2/channel@id=2","seek":0,"duration":2.537,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"title":"Listener-supported","artist":"Commercial-free","codec":"flac","trackType":"RockIt!"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/promos/2/4/228.flac?2765149","replace","start=0"],"request_id":40} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #40: {"data":{"playlist_entry_id":9},"request_id":40,"error":"success"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"228.flac?2765149"}] Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["set_property","pause",false],"request_id":41} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"play","uri":"rp2/channel@id=2","title":"Listener-supported","artist":"Commercial-free","albumart":"https://img.radioparadise.com/covers/l/103.jpg","trackType":"RockIt!","duration":2.537,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:27 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "playing"... Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] Started playback of "Listener-supported" - estimated finish time: 3/24/2026, 5:06:30 PM Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:27 volumio-pi4 volumio[12879]: verbose: [rp2] After "Listener-supported", prepare to fetch the next block in 2s (3/24/2026, 5:06:30 PM) Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #41: {"request_id":41,"error":"success"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [now-playing] Fetch metadata (rp2 plugin): {"type":"song","name":"Listener-supported","artist":"Commercial-free","duration":"2.537","uri":"rp2/channel@id=2","service":"rp2"} Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Listener-supported","artist":"Commercial-free","duration":"2.537","uri":"rp2/channel@id=2","service":""} Mar 24 17:06:27 volumio-pi4 volumio[12879]: error: [now-playing] Caught error in callback of MetdataAPI.#getFetchPromise(): Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 17:06:27 volumio-pi4 volumio[12879]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) (+) Audio --aid=1 (flac 2ch 44100Hz) Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":2.536644},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}] Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) AO: [alsa] 44100Hz stereo 2ch s16 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}] Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"play","uri":"rp2/channel@id=2","title":"Listener-supported","artist":"Commercial-free","albumart":"https://img.radioparadise.com/covers/l/103.jpg","trackType":"RockIt! - ","duration":2.537,"samplerate":"44.1 kHz","bitdepth":"16-bit","channels":2,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::ClearQueue Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::stop Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::serviceStop Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::serviceStop Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::stPlaybackTimer Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["stop"],"request_id":42} Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "stopped"... Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CorePlayQueue::clearPlayQueue Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::addQueueItems Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CorePlayQueue::addQueueItems Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6c74d3363c154f406c892ded05dc1d9 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6c74d3363c154f406c892ded05dc1d9 in service jellyfin Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6c74d3363c154f406c892ded05dc1d9 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=68e0e54ce3214f3876fdbc0615967639 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=68e0e54ce3214f3876fdbc0615967639 in service jellyfin Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=68e0e54ce3214f3876fdbc0615967639 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=09bec7a74f2f7f47750d4ba384b00a67 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=09bec7a74f2f7f47750d4ba384b00a67 in service jellyfin Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=09bec7a74f2f7f47750d4ba384b00a67 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=2edba0e1e0527d28d65e51a3a5311a3f Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=2edba0e1e0527d28d65e51a3a5311a3f in service jellyfin Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=2edba0e1e0527d28d65e51a3a5311a3f Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=7f20a0c9c48fd352db9160ccabc02c2f Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=7f20a0c9c48fd352db9160ccabc02c2f in service jellyfin Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=7f20a0c9c48fd352db9160ccabc02c2f Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #42: {"data":null,"request_id":42,"error":"success"} Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"}] Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - unsetting ourselves as current service... Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: UNSET VOLATILE: Service: rp2 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Volatile state unset, stopping playback (if any)... Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/103.jpg","uri":"rp2/channel@id=2","seek":0,"duration":2.537,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"title":"Listener-supported","artist":"Commercial-free","codec":"flac","trackType":"RockIt!"} Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 0 Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: STATE SERVICE {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/103.jpg","uri":"rp2/channel@id=2","seek":0,"duration":2.537,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"title":"Listener-supported","artist":"Commercial-free","codec":"flac","trackType":"RockIt!"} Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: CURRENT POSITION 0 Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::syncState stateService stop Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::syncState currentStatus stop Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: No code Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:29 volumio-pi4 volumio[12879]: volumio-ext-players: forward event unsetVolatile Mar 24 17:06:29 volumio-pi4 volumio[12879]: MPVPlayer onunsetVolatile called Mar 24 17:06:29 volumio-pi4 volumio[12879]: MPVPlayer calling onunsetVolatile callbacks Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "stopped"... Mar 24 17:06:29 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - unsetting ourselves as current service... Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "stopped"... Mar 24 17:06:29 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "stopped"... Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPlay Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::play index 4 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::addQueueItems Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::addQueueItems Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=fbfa26b64778e9b845cbd9ddd25a218a Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=fbfa26b64778e9b845cbd9ddd25a218a in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=fbfa26b64778e9b845cbd9ddd25a218a Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=0a81de2e769c860301a33b9af0b9db6d Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=0a81de2e769c860301a33b9af0b9db6d in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=0a81de2e769c860301a33b9af0b9db6d Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6334cf920c08bff5cb78c719e21f412 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6334cf920c08bff5cb78c719e21f412 in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6334cf920c08bff5cb78c719e21f412 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=9e6aeb1e421085e26c1725ab737e7fa6 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=9e6aeb1e421085e26c1725ab737e7fa6 in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=9e6aeb1e421085e26c1725ab737e7fa6 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=32a82aef76885e6092937e77454d4db0 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=32a82aef76885e6092937e77454d4db0 in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=32a82aef76885e6092937e77454d4db0 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=806220815f016aedfd12e4176c9702ba Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=806220815f016aedfd12e4176c9702ba in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=806220815f016aedfd12e4176c9702ba Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=a856dc5c001fe33c032517bb8c5cc662 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Exploding uri jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=a856dc5c001fe33c032517bb8c5cc662 in service jellyfin Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-browse] explodeUri: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=a856dc5c001fe33c032517bb8c5cc662 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::stop Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::play index undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 4 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::startPlaybackTimer Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 4 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/song@songId=7f20a0c9c48fd352db9160ccabc02c2f Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [jellyfin-play] Stream URL for 有著你......多麼美: http://avtm1.lan:8096/Audio/7f20a0c9c48fd352db9160ccabc02c2f/stream.dsf?static=true&mediaSourceId=7f20a0c9c48fd352db9160ccabc02c2f&tag=b6b449cc1ce00902227cb4067255da05 Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: sendMpdCommand stop took 9 milliseconds Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand clear Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Mar 24 17:06:30 volumio-pi4 volumio[12879]: ---------------------------- MPD announces system playlist update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: sendMpdCommand clear took 13 milliseconds Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand load "http://avtm1.lan:8096/Audio/7f20a0c9c48fd352db9160ccabc02c2f/stream.dsf?static=true&mediaSourceId=7f20a0c9c48fd352db9160ccabc02c2f&tag=b6b449cc1ce00902227cb4067255da05&t.dsf" Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Mar 24 17:06:30 volumio-pi4 volumio[12879]: ---------------------------- MPD announces system playlist update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Mar 24 17:06:30 volumio-pi4 volumio[12879]: ---------------------------- MPD announces system playlist update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:06:30 volumio-pi4 volumio[12879]: error: updateQueue error: null Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: ------------------------------ 29ms Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] About to reach end of stream in current block. Going to obtain next block. Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/api/play?source=24&event=2765149&elapsed=1&bitrate=4&action=play&player_id=********&info=true&chan=2&slice_num=0&episode_id=0&audio_type=P Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Obtained updated block Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] ------------- Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Block summary Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] ------------- Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Stream URL: https://audio-geo.radioparadise.com/chan/2/x/1115/4/b/1115-0.flac Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Tracks: Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 0. Lazy Eye (5:50 | elapsed: 0s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 1. Inside Out (3:23 | elapsed: 5m 50s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 2. Good Old Days (4:17 | elapsed: 9m 13s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 3. Two Hearts Beat As One (3:55 | elapsed: 13m 31s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 4. Ain't Talkin' 'Bout Love (3:44 | elapsed: 17m 26s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 5. What Jail Is Like (3:25 | elapsed: 21m 11s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] 6. Terrible Lie (4:35 | elapsed: 24m 36s) Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - skip unset volatile because unset condition is "manual" Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Going to start playback of current track Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "playing"... Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 4 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Stopping playback by current service... Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioStop Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::stop Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Setting ourselves as the current service... Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:06:30 volumio-pi4 volumio[12879]: volumio-ext-players: forward event setVolatile Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["set_property","loop-file","no"],"request_id":43} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #43: {"request_id":43,"error":"success"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"pause","albumart":"https://img.radioparadise.com/covers/l/9732.jpg","uri":"rp2/channel@id=2","seek":0,"duration":350.5,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"title":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","codec":"flac","trackType":"RockIt!"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["loadfile","https://audio-geo.radioparadise.com/chan/2/x/1115/4/b/1115-0.flac","replace","start=0"],"request_id":44} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #44: {"data":{"playlist_entry_id":10},"request_id":44,"error":"success"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":3,"prop":"idle-active","data":false},{"subscriptionId":8,"prop":"media-title","data":"1115-0.flac"}] Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["set_property","pause",false],"request_id":45} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"play","uri":"rp2/channel@id=2","title":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","albumart":"https://img.radioparadise.com/covers/l/9732.jpg","trackType":"RockIt!","duration":350.5,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "playing"... Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] Started playback of "Lazy Eye" - estimated finish time: 3/24/2026, 5:12:21 PM Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] After "Lazy Eye", the next track will start in 5m 50s (3/24/2026, 5:12:21 PM) Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/api/update_history?source=24&song_id=39664&chan=2&player_id=********&event=2765150&type=M&slice_num=0&episode_id=0&time_relative=-0&play_position_millis=0&playtime_secs=1774343191 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #45: {"request_id":45,"error":"success"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: [now-playing] Fetch metadata (rp2 plugin): {"type":"song","name":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","duration":"350.5","uri":"rp2/channel@id=2","service":"rp2"} Mar 24 17:06:30 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/siteapi.php?file=music%3A%3Asong&withWiki=true&song_id=39664 Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 17:06:30 volumio-pi4 volumio[12879]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 17:06:31 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/siteapi.php?file=music%3A%3Aartist-detail-v2022&artist_id=4075 Mar 24 17:06:31 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/siteapi.php?file=music%3A%3Aalbum-v2022&album_id=9732 Mar 24 17:06:31 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Mar 24 17:06:31 volumio-pi4 volumio[12879]: info: [now-playing] Fetch metadata (DefaultMetadataProvider): {"type":"song","name":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","duration":"350.5","uri":"rp2/channel@id=2","service":""} Mar 24 17:06:31 volumio-pi4 volumio[12879]: info: [now-playing] LRCLIB getLyrics(): song: "Lazy Eye" album: "Carnavas" artist: "Silversun Pickups" duration: "350.5" Mar 24 17:06:31 volumio-pi4 volumio[12879]: info: [now-playing] LRCLIB getLyrics() API URL: https://lrclib.net/api/get?track_name=Lazy+Eye&artist_name=Silversun+Pickups&album_name=Carnavas&duration=350.5 Mar 24 17:06:32 volumio-pi4 volumio[12879]: error: [now-playing] Error fetching lyrics from LRCLIB (URL: https://lrclib.net/api/get?track_name=Lazy+Eye&artist_name=Silversun+Pickups&album_name=Carnavas&duration=350.5): Error: Response error: 404 - Not Found Mar 24 17:06:32 volumio-pi4 volumio[12879]: at apiGet (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:20:15) Mar 24 17:06:32 volumio-pi4 volumio[12879]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Mar 24 17:06:32 volumio-pi4 volumio[12879]: at async LRCLibAPI.getLyrics (/data/plugins/user_interface/now_playing/dist/lib/api/lrclib/index.js:33:24) Mar 24 17:06:32 volumio-pi4 volumio[12879]: at async DefaultMetadataProvider.getSongInfo (/data/plugins/user_interface/now_playing/dist/lib/api/DefaultMetadataProvider.js:72:37) Mar 24 17:06:32 volumio-pi4 volumio[12879]: at async /data/plugins/user_interface/now_playing/dist/lib/api/MetadataAPI.js:132:40 Mar 24 17:06:32 volumio-pi4 volumio[12879]: error: [now-playing] Caught error in callback of MetdataAPI.#getFetchPromise(): Error: Token missing - Please provide a Genius Access Token in the Now Playing plugin settings. Mar 24 17:06:32 volumio-pi4 volumio[12879]: verbose: [rp2] Checking if next track interval requires adjusting (1/5)... Mar 24 17:06:32 volumio-pi4 volumio[12879]: verbose: [rp2] Recalculated next track interval exceeds current by 2000ms. Going to re-adjust. Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) (+) Audio --aid=1 (flac 2ch 44100Hz) Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration","data":1751.792993},{"subscriptionId":7,"prop":"audio-codec-name","data":"flac"},{"subscriptionId":9,"prop":"metadata","data":{}}] Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) AO: [alsa] 44100Hz stereo 2ch s16 Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params","data":{"samplerate":44100,"channel-count":2,"channels":"stereo","hr-channels":"stereo","format":"s16"}}] Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"play","uri":"rp2/channel@id=2","title":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","albumart":"https://img.radioparadise.com/covers/l/9732.jpg","trackType":"RockIt! - ","duration":350.5,"samplerate":"44.1 kHz","bitdepth":"16-bit","channels":2,"service":"rp2","seek":0,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:06:33 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:34 volumio-pi4 volumio[12879]: verbose: [rp2] Checking if next track interval requires adjusting (2/5)... Mar 24 17:06:34 volumio-pi4 volumio[12879]: verbose: [rp2] Recalculated next track interval exceeds current by 511.54200000001583ms. Going to re-adjust. Mar 24 17:06:36 volumio-pi4 volumio[12879]: verbose: [rp2] Checking if next track interval requires adjusting (3/5)... Mar 24 17:06:36 volumio-pi4 volumio[12879]: verbose: [rp2] Next track interval is accurate Mar 24 17:06:38 volumio-pi4 volumio[12879]: verbose: [rp2] Checking if next track interval requires adjusting (4/5)... Mar 24 17:06:38 volumio-pi4 volumio[12879]: verbose: [rp2] Next track interval is accurate Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand addid "http://avtm1.lan:8096/Audio/7f20a0c9c48fd352db9160ccabc02c2f/stream.dsf?static=true&mediaSourceId=7f20a0c9c48fd352db9160ccabc02c2f&tag=b6b449cc1ce00902227cb4067255da05&t.dsf" Mar 24 17:06:40 volumio-pi4 volumio[12879]: error: updateQueue error: null Mar 24 17:06:40 volumio-pi4 volumio[12879]: error: updateQueue error: null Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: ------------------------------ 10307ms Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: ------------------------------ 10307ms Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand addid "http://avtm1.lan:8096/Audio/7f20a0c9c48fd352db9160ccabc02c2f/stream.dsf?static=true&mediaSourceId=7f20a0c9c48fd352db9160ccabc02c2f&tag=b6b449cc1ce00902227cb4067255da05&t.dsf" took 5 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: MPD COMMAND [object Object] Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: MPD COMMAND [object Object] Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: MPD COMMAND [object Object] Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand play Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand play took 2 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand status took 8 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseState Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand status took 5 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand playlistinfo took 2 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseState Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseTrackInfo Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Pushing Favourites {"favourite":false} Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: sendMpdCommand playlistinfo took 27 milliseconds Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseTrackInfo Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: Pushing Favourites {"favourite":false} Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: [jellyfin-play]: Mark song 有著你......多麼美 as played by vvv. Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: [jellyfin-play]: Reported 'timeupdate' for song: 有著你......多麼美 (at 0 ms) Mar 24 17:06:40 volumio-pi4 volumio[12879]: info: [jellyfin-play]: Reported 'start' for song: 有著你......多麼美 (at 0 ms) Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: [rp2] Checking if next track interval requires adjusting (5/5)... Mar 24 17:06:40 volumio-pi4 volumio[12879]: verbose: [rp2] Next track interval is accurate Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPause Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreStateMachine::pause Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreStateMachine::stPlaybackTimer Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreStateMachine::servicePause Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePause Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["set_property","pause",true],"request_id":46} Mar 24 17:07:36 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "paused"... Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #46: {"request_id":46,"error":"success"} Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":1,"prop":"pause","data":true}] Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"pause","uri":"rp2/channel@id=2","title":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","albumart":"https://img.radioparadise.com/covers/l/9732.jpg","trackType":"RockIt! - ","duration":350.5,"samplerate":"44.1 kHz","bitdepth":"16-bit","channels":2,"service":"rp2","seek":63855.896,"stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"codec":"flac"} Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 24 17:07:36 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:07:37 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "paused"... Mar 24 17:07:37 volumio-pi4 volumio[12879]: verbose: [rp2] API: https://api.radioparadise.com/api/update_pause?source=24&pause=63855.896&player_id=********&event=2765150&chan=2&type=M&slice_num=0&playtime_secs=1774343258&song_id=39664&episode_id=0 Mar 24 17:07:37 volumio-pi4 volumio[12879]: info: touch_display: Setting screensaver timeout to 0 seconds. Mar 24 17:07:37 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioGetState Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::ClearQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::stop Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::serviceStop Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::serviceStop Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::stPlaybackTimer Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Send IPC command: {"command":["stop"],"request_id":47} Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "stopped"... Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::clearPlayQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::addQueueItems Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::addQueueItems Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6c74d3363c154f406c892ded05dc1d9 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6c74d3363c154f406c892ded05dc1d9 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=68e0e54ce3214f3876fdbc0615967639 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=68e0e54ce3214f3876fdbc0615967639 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPlay Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: UNSET VOLATILE: Service: rp2 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Volatile state unset, stopping playback (if any)... Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Push Volumio state: {"status":"stop","albumart":"https://img.radioparadise.com/covers/l/9732.jpg","uri":"rp2/channel@id=2","seek":63855.896,"duration":350.5,"service":"rp2","stream":false,"repeat":false,"repeatSingle":false,"random":false,"volume":100,"mute":false,"disableVolumeControl":false,"title":"Lazy Eye","artist":"Silversun Pickups","album":"Carnavas","codec":"flac","trackType":"RockIt!"} Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::servicePushState Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::pushState Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushState Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 4 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received rp2 Mar 24 17:07:55 volumio-pi4 volumio[12879]: volumio-ext-players: forward event unsetVolatile Mar 24 17:07:55 volumio-pi4 volumio[12879]: MPVPlayer onunsetVolatile called Mar 24 17:07:55 volumio-pi4 volumio[12879]: MPVPlayer calling onunsetVolatile callbacks Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: [rp2] Waiting for player event "stopped"... Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::play index 1 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::addQueueItems Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::addQueueItems Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Preload queue cleared Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=09bec7a74f2f7f47750d4ba384b00a67 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=09bec7a74f2f7f47750d4ba384b00a67 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=2edba0e1e0527d28d65e51a3a5311a3f Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=2edba0e1e0527d28d65e51a3a5311a3f Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=7f20a0c9c48fd352db9160ccabc02c2f Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=7f20a0c9c48fd352db9160ccabc02c2f Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=fbfa26b64778e9b845cbd9ddd25a218a Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=fbfa26b64778e9b845cbd9ddd25a218a Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=0a81de2e769c860301a33b9af0b9db6d Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=0a81de2e769c860301a33b9af0b9db6d Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6334cf920c08bff5cb78c719e21f412 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=b6334cf920c08bff5cb78c719e21f412 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=9e6aeb1e421085e26c1725ab737e7fa6 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=9e6aeb1e421085e26c1725ab737e7fa6 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=32a82aef76885e6092937e77454d4db0 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=32a82aef76885e6092937e77454d4db0 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=806220815f016aedfd12e4176c9702ba Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=806220815f016aedfd12e4176c9702ba Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Adding Item to queue: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=a856dc5c001fe33c032517bb8c5cc662 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Using cached record of: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/albums@parentId=e1e3ec17ee4defbd3a633407f833adb2@sortBy=DateCreated%2CSortName@sortOrder=Descending%2CAscending@fixedView=latest@startIndex=94@noExplode=1/songs@albumId=464f1eca23bb18aaf28fb76a3d2f945e/song@songId=a856dc5c001fe33c032517bb8c5cc662 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::stop Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreCommandRouter::volumioPushQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::saveQueue Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::play index undefined Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::updateTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrackBlock Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 1 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CoreStateMachine::startPlaybackTimer Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: CorePlayQueue::getTrack 1 Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/vvv@54189ce4319a483c9a68c49cb3002497/song@songId=68e0e54ce3214f3876fdbc0615967639 Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: [rp2] Received player event "stopped"... Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Got response for command #47: {"data":null,"request_id":47,"error":"success"} Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"}] Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Status update -> property-change events: [{"subscriptionId":2,"prop":"duration"},{"subscriptionId":3,"prop":"idle-active","data":true},{"subscriptionId":8,"prop":"media-title"},{"subscriptionId":9,"prop":"metadata"}] Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [rp2] [mpv] (PID: 13486) Player status "stopped" - unsetting ourselves as current service... Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: [jellyfin-play] Stream URL for 把你怨恨: http://avtm1.lan:8096/Audio/68e0e54ce3214f3876fdbc0615967639/stream.dsf?static=true&mediaSourceId=68e0e54ce3214f3876fdbc0615967639&tag=b6b449cc1ce00902227cb4067255da05 Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand stop Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Mar 24 17:07:55 volumio-pi4 volumio[12879]: ---------------------------- MPD announces state update: player Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand stop took 12 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand clear Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Mar 24 17:07:55 volumio-pi4 volumio[12879]: ---------------------------- MPD announces system playlist update Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Ignoring MPD Status Update Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand status took 2 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand status took 1 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand clear took 2 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand load "http://avtm1.lan:8096/Audio/68e0e54ce3214f3876fdbc0615967639/stream.dsf?static=true&mediaSourceId=68e0e54ce3214f3876fdbc0615967639&tag=b6b449cc1ce00902227cb4067255da05&t.dsf" Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Mar 24 17:07:55 volumio-pi4 volumio[12879]: ---------------------------- MPD announces state update: player Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: Mar 24 17:07:55 volumio-pi4 volumio[12879]: ---------------------------- MPD announces state update: player Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ControllerMpd::getState Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::sendMpdCommand status Mar 24 17:07:55 volumio-pi4 volumio[12879]: error: updateQueue error: null Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ------------------------------ 7ms Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseTrackInfo Mar 24 17:07:55 volumio-pi4 volumio[12879]: verbose: ControllerMpd::parseTrackInfo Mar 24 17:07:55 volumio-pi4 volumio[12879]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Mar 24 17:07:55 volumio-pi4 volumio[12879]: info: ------------------------------ 13ms Mar 24 17:07:55 volumio-pi4 volumio[12879]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 17:07:55 volumio-pi4 volumio[12879]: TypeError: Cannot read properties of undefined (reading 'split') Mar 24 17:07:55 volumio-pi4 volumio[12879]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) Mar 24 17:07:55 volumio-pi4 volumio[12879]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Mar 24 17:07:55 volumio-pi4 volumio[12879]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Mar 24 17:07:55 volumio-pi4 volumio[12879]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 24 17:07:55 volumio-pi4 sudo[14361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-24 17:06' Mar 24 17:07:55 volumio-pi4 sudo[14361]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"