May 28 16:10:23 dioracast go-librespot[1581]: time="2026-05-28T16:10:23+02:00" level=trace msg="sent dealer ping" May 28 16:10:23 dioracast go-librespot[1581]: time="2026-05-28T16:10:23+02:00" level=trace msg="received dealer pong" May 28 16:10:30 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:30 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:10:30 dioracast volumio[1194]: info: Prefetching next song May 28 16:10:30 dioracast volumio[1194]: info: [1779977430784] ControllerSpotify::prefetch May 28 16:10:30 dioracast volumio[1194]: info: Sending Spotify command with payload to local API: /player/add_to_queue May 28 16:10:30 dioracast go-librespot[1581]: time="2026-05-28T16:10:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:10:30 dioracast go-librespot[1581]: time="2026-05-28T16:10:30+02:00" level=trace msg="prefetch as soon as possible" May 28 16:10:30 dioracast go-librespot[1581]: time="2026-05-28T16:10:30+02:00" level=debug msg="prefetching next track" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:31 dioracast go-librespot[1581]: time="2026-05-28T16:10:31+02:00" level=debug msg="selected format OGG_VORBIS_320 (634f05d6f07f1125fdd796e61751d2772cb48a5c)" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:31 dioracast go-librespot[1581]: time="2026-05-28T16:10:31+02:00" level=debug msg="requested aes key for file 634f05d6f07f1125fdd796e61751d2772cb48a5c, gid: 0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=debug msg="fetched first chunk of 21, total size is 10966024 bytes" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=info msg="prefetched track \"Popłoch\" (duration: 279960ms)" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=debug msg="fetched chunk 2/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=debug msg="fetched chunk 3/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:32 dioracast go-librespot[1581]: time="2026-05-28T16:10:32+02:00" level=debug msg="fetched chunk 1/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=trace msg="emitting websocket event: not_playing" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:7chLZYAfULDTlGoGC1yrbO","uri":"spotify:track:7chLZYAfULDTlGoGC1yrbO","play_origin":"go-librespot"}} May 28 16:10:34 dioracast volumio[1194]: error: Failed to decode event: not_playing May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=trace msg="emitting websocket event: will_play" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=info msg="loaded track \"Popłoch\" (paused: false, position: 0ms, duration: 279960ms, prefetched: true)" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:7chLZYAfULDTlGoGC1yrbO","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","play_origin":"go-librespot"}} May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=trace msg="scheduling prefetch in 250s" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=trace msg="emitting websocket event: metadata" May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","name":"Popłoch","artist_names":["Mech"],"album_name":"X","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","position":0,"duration":279960,"release_date":"year:2014","track_number":8,"disc_number":1}} May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:10:34 dioracast go-librespot[1581]: time="2026-05-28T16:10:34+02:00" level=trace msg="emitting websocket event: playing" May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:7chLZYAfULDTlGoGC1yrbO","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","resume":false,"play_origin":"go-librespot"}} May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: PUSH STATE SPOTIFY May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: {"status":"play","service":"spop","title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","seek":0,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 28 16:10:34 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:10:34 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:34 dioracast volumio[1194]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","seek":0,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 28 16:10:34 dioracast volumio[1194]: verbose: CURRENT POSITION 1 May 28 16:10:34 dioracast volumio[1194]: info: CoreStateMachine::syncState stateService play May 28 16:10:34 dioracast volumio[1194]: info: CoreStateMachine::syncState currentStatus play May 28 16:10:34 dioracast volumio[1194]: info: Received an update from plugin. extracting info from payload May 28 16:10:34 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:10:34 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:34 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:10:34 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:10:34 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:10:34 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:34 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:10:34 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:10:34 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 100 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: false May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 100 May 28 16:10:34 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: false May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: PUSH STATE SPOTIFY May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: {"status":"play","service":"spop","title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","seek":0,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:10:35 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:35 dioracast volumio[1194]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","seek":0,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 28 16:10:35 dioracast volumio[1194]: verbose: CURRENT POSITION 1 May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::syncState stateService play May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::syncState currentStatus play May 28 16:10:35 dioracast volumio[1194]: info: Received an update from plugin. extracting info from payload May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:10:35 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:10:35 dioracast volumio[1194]: info: CorePlayQueue::getTrack 1 May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:10:35 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:10:35 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: false May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: false May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::startPlaybackTimer May 28 16:10:35 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:10:35 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:10:35 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:10:35 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:10:35 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 100 May 28 16:10:35 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: false May 28 16:10:48 dioracast go-librespot[1581]: time="2026-05-28T16:10:48+02:00" level=debug msg="fetched chunk 4/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:10:49 dioracast go-librespot[1581]: time="2026-05-28T16:10:49+02:00" level=trace msg="received accesspoint ping" May 28 16:10:49 dioracast go-librespot[1581]: time="2026-05-28T16:10:49+02:00" level=trace msg="received accesspoint pong ack" May 28 16:10:53 dioracast go-librespot[1581]: time="2026-05-28T16:10:53+02:00" level=trace msg="sent dealer ping" May 28 16:10:53 dioracast go-librespot[1581]: time="2026-05-28T16:10:53+02:00" level=trace msg="received dealer pong" May 28 16:11:00 dioracast go-librespot[1581]: time="2026-05-28T16:11:00+02:00" level=debug msg="fetched chunk 5/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:11:02 dioracast volumio[1194]: info: VolumeController::SetAlsaVolume71 May 28 16:11:02 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:02 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:11:02 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:02 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:02 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:11:02 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 71 May 28 16:11:02 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 99 May 28 16:11:02 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 71 May 28 16:11:02 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: true May 28 16:11:02 dioracast volumio[1194]: info: Setting Spotify Volume from Volumio: 71 May 28 16:11:03 dioracast volumio[1194]: info: VolumeController::SetAlsaVolume39 May 28 16:11:03 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:03 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:11:03 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:03 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:03 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 71 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 39 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: true May 28 16:11:03 dioracast volumio[1194]: info: Setting Spotify Volume from Volumio: 39 May 28 16:11:03 dioracast volumio[1194]: info: VolumeController::SetAlsaVolume33 May 28 16:11:03 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:03 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:11:03 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:03 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:03 dioracast volumio[1194]: info: FusionDsp - Volumio is playing May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: SPOTIFY VOLUME 39 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: VOLUMIO VOLUME 33 May 28 16:11:03 dioracast volumio[1194]: SPOTIFY: DELTA VOLUME ENOUGH: true May 28 16:11:03 dioracast volumio[1194]: info: Setting Spotify Volume from Volumio: 33 May 28 16:11:04 dioracast volumio[1194]: SPOTIFY: SETTING SPOTIFY VOLUME 33 May 28 16:11:04 dioracast volumio[1194]: info: Sending Spotify command with payload to local API: /player/volume May 28 16:11:04 dioracast go-librespot[1581]: time="2026-05-28T16:11:04+02:00" level=debug msg="update volume requested to 21626/65535" May 28 16:11:05 dioracast go-librespot[1581]: time="2026-05-28T16:11:05+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 28 16:11:05 dioracast go-librespot[1581]: time="2026-05-28T16:11:05+02:00" level=trace msg="emitting websocket event: volume" May 28 16:11:05 dioracast volumio[1194]: SPOTIFY: received: {"type":"volume","data":{"value":33,"max":100}} May 28 16:11:05 dioracast volumio[1194]: SPOTIFY: RECEIVED SPOTIFY VOLUME 33 May 28 16:11:13 dioracast go-librespot[1581]: time="2026-05-28T16:11:13+02:00" level=debug msg="fetched chunk 6/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:11:22 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: jellyfin , handleBrowseUri May 28 16:11:22 dioracast volumio[1194]: info: [jellyfin-browse] browseUri: jellyfin May 28 16:11:22 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:23 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: jellyfin , handleBrowseUri May 28 16:11:23 dioracast volumio[1194]: info: [jellyfin-browse] browseUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21 May 28 16:11:23 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): {"userId":"009c5df829474380832367bd6fb5417d","enableImageTypes":["Primary"],"imageTypeLimit":1,"recursive":true,"startIndex":0,"limit":47,"sortBy":["SortName"],"sortOrder":["Ascending"]} May 28 16:11:23 dioracast go-librespot[1581]: time="2026-05-28T16:11:23+02:00" level=trace msg="sent dealer ping" May 28 16:11:23 dioracast go-librespot[1581]: time="2026-05-28T16:11:23+02:00" level=trace msg="received dealer pong" May 28 16:11:23 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): https://jellyfin.igoadm.pl/UserViews?userId=009c5df829474380832367bd6fb5417d May 28 16:11:23 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): {"userId":"009c5df829474380832367bd6fb5417d","enableImageTypes":["Primary"],"imageTypeLimit":1,"recursive":true,"parentId":"148c709a75698abc5e97b303f715b8e5","startIndex":0,"limit":11,"sortBy":["DateCreated","SortName"],"sortOrder":["Descending","Ascending"],"includeItemTypes":["MusicAlbum"]} May 28 16:11:23 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): https://jellyfin.igoadm.pl/Items?userId=009c5df829474380832367bd6fb5417d&startIndex=0&limit=11&recursive=true&sortOrder=Descending&sortOrder=Ascending&parentId=148c709a75698abc5e97b303f715b8e5&includeItemTypes=MusicAlbum&sortBy=DateCreated&sortBy=SortName&imageTypeLimit=1&enableImageTypes=Primary May 28 16:11:23 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:23 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:25 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: jellyfin , handleBrowseUri May 28 16:11:25 dioracast volumio[1194]: info: [jellyfin-browse] browseUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5 May 28 16:11:25 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): {"userId":"009c5df829474380832367bd6fb5417d","enableImageTypes":["Primary"],"imageTypeLimit":1,"recursive":true,"parentId":"6d3726f110c7c0ddc2b2066a3e1927a5","startIndex":0,"sortBy":["SortName"],"sortOrder":["Ascending"],"fields":["MediaSources"],"includeItemTypes":["Audio"]} May 28 16:11:25 dioracast volumio[1194]: verbose: [jellyfin] getItemsFromAPI(): https://jellyfin.igoadm.pl/Items?userId=009c5df829474380832367bd6fb5417d&startIndex=0&recursive=true&sortOrder=Ascending&parentId=6d3726f110c7c0ddc2b2066a3e1927a5&fields=MediaSources&includeItemTypes=Audio&sortBy=SortName&imageTypeLimit=1&enableImageTypes=Primary May 28 16:11:26 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=5bff308e8fbe3884e37e849556d68a78 May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=6e47d806e5b2d012e873612ba0047a3c May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=d20c7ced6f856169e26601645cb52cc0 May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=f0fb837c14430cd52a31cc7153163844 May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=052f6f87062a245d68c8eaf11b63e6b3 May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=80ff897a81b1b4488525258d43f2c9bc May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=bffc9ef5e99fd3c96d8a658e9365f729 May 28 16:11:26 dioracast volumio[1194]: info: Preloading song: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=ca5d6ab886f347e084907ff94d9758b6 May 28 16:11:26 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:26 dioracast volumio[1194]: info: No valid Plugin REST Endpoint May 28 16:11:26 dioracast volumio[1194]: info: No valid Plugin REST Endpoint May 28 16:11:26 dioracast go-librespot[1581]: time="2026-05-28T16:11:26+02:00" level=debug msg="fetched chunk 7/20, size: 524288" uri="spotify:track:0pIQTtvMM70v7HjcWzBOQW" May 28 16:11:36 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioReplaceandPlayItems May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::ClearQueue May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::stop May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::stPlaybackTimer May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::updateTrackBlock May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrackBlock May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::serviceStop May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrack 7 May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::serviceStop May 28 16:11:36 dioracast volumio[1194]: info: Spotify Stop May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: SPOTIFY STOP May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: {"status":"play","position":7,"title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d0000b273530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","codec":"ogg","seek":27785,"duration":279,"samplerate":"320 kbps","bitdepth":"16 bit","random":true,"repeat":null,"repeatSingle":false,"consume":false,"volume":33,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} May 28 16:11:36 dioracast volumio[1194]: info: Sending Spotify command to local API: /player/pause May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::clearPlayQueue May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::saveQueue May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushQueue May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::addQueueItems May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::addQueueItems May 28 16:11:36 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=5bff308e8fbe3884e37e849556d68a78 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=5bff308e8fbe3884e37e849556d68a78 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=5bff308e8fbe3884e37e849556d68a78 May 28 16:11:36 dioracast volumio[1194]: info: FusionDsp - Volumio is not playing May 28 16:11:36 dioracast volumio[1194]: info: FusionDsp - Clipped samples monitor stopped May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 28 16:11:36 dioracast go-librespot[1581]: time="2026-05-28T16:11:36+02:00" level=debug msg="pause track at 61475ms" May 28 16:11:36 dioracast go-librespot[1581]: time="2026-05-28T16:11:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushQueue May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::saveQueue May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::updateTrackBlock May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrackBlock May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioPlay May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::play index 0 May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::addQueueItems May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::addQueueItems May 28 16:11:36 dioracast volumio[1194]: info: Preload queue cleared May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=6e47d806e5b2d012e873612ba0047a3c May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=6e47d806e5b2d012e873612ba0047a3c in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=6e47d806e5b2d012e873612ba0047a3c May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=d20c7ced6f856169e26601645cb52cc0 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=d20c7ced6f856169e26601645cb52cc0 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=d20c7ced6f856169e26601645cb52cc0 May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=f0fb837c14430cd52a31cc7153163844 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=f0fb837c14430cd52a31cc7153163844 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=f0fb837c14430cd52a31cc7153163844 May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=052f6f87062a245d68c8eaf11b63e6b3 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=052f6f87062a245d68c8eaf11b63e6b3 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=052f6f87062a245d68c8eaf11b63e6b3 May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=80ff897a81b1b4488525258d43f2c9bc May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=80ff897a81b1b4488525258d43f2c9bc in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=80ff897a81b1b4488525258d43f2c9bc May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=bffc9ef5e99fd3c96d8a658e9365f729 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=bffc9ef5e99fd3c96d8a658e9365f729 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=bffc9ef5e99fd3c96d8a658e9365f729 May 28 16:11:36 dioracast volumio[1194]: info: Adding Item to queue: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=ca5d6ab886f347e084907ff94d9758b6 May 28 16:11:36 dioracast volumio[1194]: info: Exploding uri jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=ca5d6ab886f347e084907ff94d9758b6 in service jellyfin May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-browse] explodeUri: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/songs@albumId=6d3726f110c7c0ddc2b2066a3e1927a5/song@songId=ca5d6ab886f347e084907ff94d9758b6 May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::stop May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::play index undefined May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrack 0 May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::startPlaybackTimer May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrack 0 May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/song@songId=5bff308e8fbe3884e37e849556d68a78 May 28 16:11:36 dioracast go-librespot[1581]: time="2026-05-28T16:11:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 28 16:11:36 dioracast go-librespot[1581]: time="2026-05-28T16:11:36+02:00" level=trace msg="emitting websocket event: paused" May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:7chLZYAfULDTlGoGC1yrbO","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","play_origin":"go-librespot"}} May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: PUSH STATE SPOTIFY May 28 16:11:36 dioracast volumio[1194]: SPOTIFY: {"status":"pause","service":"spop","title":"Popłoch","artist":"Mech","album":"X","albumart":"https://i.scdn.co/image/ab67616d00001e02530cbe117bb5924039cd60df","uri":"spotify:track:0pIQTtvMM70v7HjcWzBOQW","trackType":"spotify","seek":62000,"duration":279,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrack 0 May 28 16:11:36 dioracast volumio[1194]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received spop May 28 16:11:36 dioracast volumio[1194]: info: [jellyfin-play] Stream URL for Piłem z diabłem bruderschaft: https://jellyfin.igoadm.pl/Audio/5bff308e8fbe3884e37e849556d68a78/stream.mpc?static=true&mediaSourceId=5bff308e8fbe3884e37e849556d68a78&tag=688312c702b448a481d72ff1184a5ce7 May 28 16:11:36 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand stop May 28 16:11:36 dioracast volumio[1194]: info: sendMpdCommand stop took 1 milliseconds May 28 16:11:36 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand clear May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: sendMpdCommand clear took 1 milliseconds May 28 16:11:36 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand load "https://jellyfin.igoadm.pl/Audio/5bff308e8fbe3884e37e849556d68a78/stream.mpc?static=true&mediaSourceId=5bff308e8fbe3884e37e849556d68a78&tag=688312c702b448a481d72ff1184a5ce7&t.mpc" May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: error: updateQueue error: null May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 5ms May 28 16:11:36 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushQueue May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::saveQueue May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::updateTrackBlock May 28 16:11:36 dioracast volumio[1194]: info: CorePlayQueue::getTrackBlock May 28 16:11:36 dioracast volumio[1194]: error: updateQueue error: null May 28 16:11:36 dioracast volumio[1194]: error: updateQueue error: null May 28 16:11:36 dioracast volumio[1194]: error: updateQueue error: null May 28 16:11:36 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand addid "https://jellyfin.igoadm.pl/Audio/5bff308e8fbe3884e37e849556d68a78/stream.mpc?static=true&mediaSourceId=5bff308e8fbe3884e37e849556d68a78&tag=688312c702b448a481d72ff1184a5ce7&t.mpc" May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 402ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 401ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 401ms May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: sendMpdCommand addid "https://jellyfin.igoadm.pl/Audio/5bff308e8fbe3884e37e849556d68a78/stream.mpc?static=true&mediaSourceId=5bff308e8fbe3884e37e849556d68a78&tag=688312c702b448a481d72ff1184a5ce7&t.mpc" took 1 milliseconds May 28 16:11:36 dioracast volumio[1194]: verbose: MPD COMMAND [object Object] May 28 16:11:36 dioracast volumio[1194]: verbose: MPD COMMAND [object Object] May 28 16:11:36 dioracast volumio[1194]: verbose: MPD COMMAND [object Object] May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 4ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 3ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 2ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 1ms May 28 16:11:36 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService mpd May 28 16:11:36 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand play May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: May 28 16:11:36 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:36 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 6ms May 28 16:11:36 dioracast volumio[1194]: info: sendMpdCommand play took 6 milliseconds May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 5ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 5ms May 28 16:11:36 dioracast volumio[1194]: info: ------------------------------ 4ms May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 4 milliseconds May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 6 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 5 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 5 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 5 milliseconds May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 5 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 5 milliseconds May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::pushState May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 0 May 28 16:11:37 dioracast volumio[1194]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":401,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Piłem z diabłem bruderschaft","artist":"Mech","album":"Bluffmania","uri":"https://jellyfin.igoadm.pl/Audio/5bff308e8fbe3884e37e849556d68a78/stream.mpc?static=true&mediaSourceId=5bff308e8fbe3884e37e849556d68a78&tag=688312c702b448a481d72ff1184a5ce7&t.mpc","trackType":"mpc"} May 28 16:11:37 dioracast volumio[1194]: verbose: CURRENT POSITION 0 May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::syncState stateService play May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::syncState currentStatus stop May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 11ms May 28 16:11:37 dioracast kernel: xhci_hcd 0000:01:00.0: ERROR Transfer event for disabled endpoint slot 2 ep 3 May 28 16:11:37 dioracast kernel: xhci_hcd 0000:01:00.0: @000000040cd100e0 00000000 00000000 0e000000 02048001 May 28 16:11:37 dioracast volumio[1194]: info: camilladsp respawn in 100 ms (attempt 1/10) May 28 16:11:37 dioracast volumio[1194]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 May 28 16:11:37 dioracast volumio[1194]: info: FusionDsp - ---- read samplerate from file: 44100 May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 262 milliseconds May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces system playlist update May 28 16:11:37 dioracast volumio[1194]: info: Ignoring MPD Status Update May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: May 28 16:11:37 dioracast volumio[1194]: ---------------------------- MPD announces state update: player May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::getState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::sendMpdCommand status May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 263 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 262 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 262 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 262 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 262 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 261 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand status took 260 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 259 milliseconds May 28 16:11:37 dioracast volumio[1194]: info: sendMpdCommand playlistinfo took 2 milliseconds May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseState May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: verbose: ControllerMpd::parseTrackInfo May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::pushState May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 0 May 28 16:11:37 dioracast volumio[1194]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 16:11:37 dioracast volumio[1194]: verbose: CURRENT POSITION 0 May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::syncState stateService stop May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::syncState currentStatus play May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::play index undefined May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::setConsumeUpdateService undefined May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:37 dioracast volumio[1194]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 28 16:11:37 dioracast volumio[1194]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 28 16:11:37 dioracast volumio[1194]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::pushState May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received mpd May 28 16:11:37 dioracast volumio[1194]: info: ControllerMpd::pushState May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::servicePushState May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current jellyfin Received mpd May 28 16:11:37 dioracast volumio[1194]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::startPlaybackTimer May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: [jellyfin-play] clearAddPlayTrack: jellyfin/ikopr@e07f5aab29374a898ffe85b636deea21/song@songId=bffc9ef5e99fd3c96d8a658e9365f729 May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 282ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 287ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 287ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 286ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 279ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 279ms May 28 16:11:37 dioracast volumio[1194]: info: ------------------------------ 284ms May 28 16:11:37 dioracast volumio[1194]: info: CoreStateMachine::pushState May 28 16:11:37 dioracast volumio[1194]: info: CorePlayQueue::getTrack 6 May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 16:11:37 dioracast volumio[1194]: info: CoreCommandRouter::volumioPushState May 28 16:11:37 dioracast volumio[1194]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 16:11:37 dioracast volumio[1194]: TypeError: Cannot read properties of undefined (reading 'split') May 28 16:11:37 dioracast volumio[1194]: at Promise._successFn (/volumio/app/plugins/music_service/mpd/index.js:280:60) May 28 16:11:37 dioracast volumio[1194]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 28 16:11:37 dioracast volumio[1194]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) May 28 16:11:37 dioracast volumio[1194]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 16:11:37 dioracast sudo[15826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-28 16:10' May 28 16:11:37 dioracast sudo[15826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"