May 26 14:22:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:22:04+02:00" level=trace msg="sent dealer ping" May 26 14:22:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:22:04+02:00" level=trace msg="received dealer pong" May 26 14:22:33 music-hq-1 go-librespot[1540]: time="2026-05-26T14:22:33+02:00" level=trace msg="sent dealer ping" May 26 14:22:34 music-hq-1 go-librespot[1540]: time="2026-05-26T14:22:34+02:00" level=trace msg="received dealer pong" May 26 14:22:58 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 26 14:22:58 music-hq-1 volumio[1214]: info: In handleBrowseUri, curUri=spotify May 26 14:22:58 music-hq-1 volumio[1214]: info: New access token = BQBsemchNTBKAf0ldR_e7DPDomdtQxVXGjl9HT7D2Jdo7oQHLpy0LnIGDTvnORqIqFS86QaZjJloCPZRPZ3COsOyCWzvGiFu634TFXX9aeoDe-TGxy_nW1Er0zx28U8d7a8_QQchQ9fi-zDSoG2lsg8JgvbMR_gSgtiBvm0GRZPkkg1q1w4mzcuywm3Ae3mAdT421FFY4u20q9l0MaPYfcmpd89yhBgXBfMr-2GSo6-G2IX18Cf26slyNQ56Oet4Im57wigKcukXE1NNeH75TYLBQmifPp_uG6wJakJzo9TCooGWwnCsV7GSrXMMeg May 26 14:22:58 music-hq-1 volumio[1214]: info: New access token = BQArsY6sp2-LuW9izVmXvZZgrDAIA-bhyJBgJEHBRvRDytvEOO70sFBaDrJvtHWqN-mmEaX_Ko1vAKy0qvVEIw-sJ1xdUn72UrfeEG72DQDJT1VnjscBQc0X2jHUEdczjpR6yWOkzHJXl3tj1QePggALFfVncFcolAYT1qZ2R0DpwqgpQX2PU7kZtoFbCwZ1c3yKbkBUfHj15s9asSKJDzYAp9IJbk4GMHvIszeP6AWL_MT5VeiZsKKDO1tN8zqmt91oDo2og6yA3kfMJIl-tLJ-bhbelJ_YGmn0HFXX0_wU5QGcN8oSeg9HMzezKw May 26 14:22:58 music-hq-1 volumio[1214]: info: New access token = BQCsU0-vmzYuJVobVV1OniLvNtTvuCj2YmTANbm1DOtF6fhqa3Dl0YEr1R_6LbgnEI4bvHxwG9HBzWebo3g1SeA308kSp_OYSpZFeemwEF6_A8ASjBY1cDxKrJdqSj45kJDreFJmFPkjYZqfAEyMkQXWzLHRq_o_7lxuFkoTEjSO_18InV48zkYtmHQesEJ7rS9QreQSdnB5mh9_Q8OWExaR8BhNvXGE4S6gI5DhK0xmGJ2utvvya-TbPAfPndN53JjErKrDME-A7BgmBK9cDFkksPbGxYgFYhBYhEtPIebgSnI5kav3mACChcTV-g May 26 14:22:59 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:22:59 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:22:59 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:22:59 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:01 music-hq-1 volumio[1214]: Searching plugin music_service/spop May 26 14:23:01 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: spop , search May 26 14:23:02 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:04+02:00" level=trace msg="sent dealer ping" May 26 14:23:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:04+02:00" level=trace msg="received dealer pong" May 26 14:23:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:04+02:00" level=trace msg="received accesspoint ping" May 26 14:23:04 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:04+02:00" level=trace msg="received accesspoint pong ack" May 26 14:23:04 music-hq-1 volumio[1214]: Searching plugin music_service/spop May 26 14:23:04 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: spop , search May 26 14:23:05 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:06 music-hq-1 volumio[1214]: Searching plugin music_service/spop May 26 14:23:06 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: spop , search May 26 14:23:07 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:20 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: soundcloud , handleBrowseUri May 26 14:23:20 music-hq-1 volumio[1214]: info: [soundcloud] browseUri: soundcloud May 26 14:23:21 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:21 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2316702212 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2309331251 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2319693767 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2323772957 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2325843854 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2321705381 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2312554022 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2325125372 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2324452430 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2321292941 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preloading song: soundcloud/tracks@topFeatured=1@inSection=1@title=Top-Featured%20Tracks/track@trackId=2311938449 May 26 14:23:21 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:21 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:21 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:22 music-hq-1 volumio[1214]: Searching plugin music_service/soundcloud May 26 14:23:22 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: soundcloud , search May 26 14:23:23 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:26 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::ClearQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::serviceStop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::serviceStop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stPlaybackTimer May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Send IPC command: {"command":["stop"],"request_id":51} May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::clearPlayQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::addQueueItems May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::addQueueItems May 26 14:23:26 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1468923616 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1468923616 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1468923616 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1468923616 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPlay May 26 14:23:26 music-hq-1 volumio[1214]: verbose: UNSET VOLATILE: Service: soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Volatile state unset, stopping playback (if any)... May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Push Volumio state: {"status":"stop","albumart":"/albumart","uri":"","seek":5158295.306,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 2 May 26 14:23:26 music-hq-1 volumio[1214]: verbose: STATE SERVICE {"status":"stop","albumart":"/albumart","uri":"","seek":5158295.306,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: verbose: CURRENT POSITION 2 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState stateService stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState currentStatus stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: info: No code May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::play index 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::addQueueItems May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::addQueueItems May 26 14:23:26 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=2224628681 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=2224628681 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=2224628681 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1221785623 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1221785623 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1221785623 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1229440000 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1229440000 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1229440000 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1473142150 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1473142150 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1473142150 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1620930654 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1620930654 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1620930654 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=243737844 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=243737844 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=243737844 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=665122520 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=665122520 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=665122520 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=299990876 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=299990876 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=299990876 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=37901324 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=37901324 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=37901324 May 26 14:23:26 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1850859912 May 26 14:23:26 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1850859912 in service soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotec%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotec%20sancer'/track@trackId=1850859912 May 26 14:23:26 music-hq-1 volumio5-onboarding[1493]: time=2026-05-26T14:23:26.279+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 5158295.306 into Go struct field State.seek of type int" May 26 14:23:26 music-hq-1 volumio5-onboarding[1493]: time=2026-05-26T14:23:26.281+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 5158295.306 into Go struct field State.seek of type int" May 26 14:23:26 music-hq-1 volumio5-onboarding[1493]: time=2026-05-26T14:23:26.282+02:00 level=ERROR msg="failed to unmarshal pushState event" component=volumio/socket error="json: cannot unmarshal number 5158295.306 into Go struct field State.seek of type int" May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::play index undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::startPlaybackTimer May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] clearAddPlayTrack: soundcloud/track@trackId=1468923616 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=2224628681 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1221785623 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1229440000 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1473142150 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1620930654 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=243737844 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=665122520 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=299990876 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=37901324 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1850859912 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Got response for command #51: {"data":null,"request_id":51,"error":"success"} May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Status update -> property-change events: [{"subscriptionId":6,"prop":"audio-params"},{"subscriptionId":7,"prop":"audio-codec-name"}] May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Stopping playback by current service... May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioStop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Setting ourselves as the current service... May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"pause","albumart":"https://i1.sndcdn.com/artworks-bStq1M5Bk69wQSmU-Nw8NvA-t500x500.jpg","uri":"soundcloud/track@trackId=1468923616","seek":0,"duration":0,"service":"soundcloud","artist":"Techno Germany","album":"SoundCloud Track","name":"Premiere: SANCER - Discotek (Original Mix) [BLCKWRKS018]","title":"Premiere: SANCER - Discotek (Original Mix) [BLCKWRKS018]","trackType":"aac","samplerate":"160 kbps","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"play","uri":"soundcloud/track@trackId=1468923616","title":"Premiere: SANCER - Discotek (Original Mix) [BLCKWRKS018]","artist":"Techno Germany","album":"SoundCloud Track","albumart":"https://i1.sndcdn.com/artworks-bStq1M5Bk69wQSmU-Nw8NvA-t500x500.jpg","trackType":"aac","duration":-1,"samplerate":"160 kbps","service":"soundcloud","seek":0,"isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) 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"}] May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [mpv] (PID: 24392) Player status "stopped" - unsetting ourselves as current service... May 26 14:23:26 music-hq-1 volumio[1214]: verbose: UNSET VOLATILE: Service: soundcloud May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Volatile state unset, stopping playback (if any)... May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"stop","albumart":"/albumart","uri":"","seek":0,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:26 music-hq-1 volumio[1214]: verbose: STATE SERVICE {"status":"stop","albumart":"/albumart","uri":"","seek":0,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: verbose: CURRENT POSITION 0 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState stateService stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState currentStatus play May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::play index undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stPlaybackTimer May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::startPlaybackTimer May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] clearAddPlayTrack: soundcloud/track@trackId=2224628681 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:26 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Stopping playback by current service... May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioStop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Setting ourselves as the current service... May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"pause","albumart":"https://i1.sndcdn.com/artworks-h6VxwMrySNW2SyPI-iiSKyA-t500x500.jpg","uri":"soundcloud/track@trackId=2224628681","seek":0,"duration":0,"service":"soundcloud","artist":"MAIJO SANCCER 🎧","album":"SoundCloud Track","name":"Omnia Discoteca Elda","title":"Omnia Discoteca Elda","trackType":"aac","samplerate":"160 kbps","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:26 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:26 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:26 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [aef123b0] adaptive demux: Changing stream format Unknown -> MP4 May 26 14:23:27 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b06295e8] mp4 demux: Fragment sequence discontinuity detected 1 != 0 May 26 14:23:27 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [aef123b0] http demux error: local stream 1 error: Cancellation (0x8) May 26 14:23:27 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [aef123b0] http demux error: local stream 3 error: Cancellation (0x8) May 26 14:23:27 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [aef123b0] http demux error: local stream 1 error: Cancellation (0x8) May 26 14:23:28 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] adaptive demux: Changing stream format Unknown -> MP4 May 26 14:23:28 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b5e46458] mp4 demux: Fragment sequence discontinuity detected 1 != 0 May 26 14:23:28 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 1 error: Cancellation (0x8) May 26 14:23:29 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 3 error: Cancellation (0x8) May 26 14:23:30 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 5 error: Cancellation (0x8) May 26 14:23:31 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 7 error: Cancellation (0x8) May 26 14:23:31 music-hq-1 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... May 26 14:23:32 music-hq-1 systemd[1]: setdatetime-helper.service: Deactivated successfully. May 26 14:23:32 music-hq-1 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. May 26 14:23:34 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:34+02:00" level=trace msg="sent dealer ping" May 26 14:23:34 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:34+02:00" level=trace msg="received dealer pong" May 26 14:23:37 music-hq-1 volumio[1214]: Searching plugin music_service/soundcloud May 26 14:23:37 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: soundcloud , search May 26 14:23:37 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:38 music-hq-1 volumio[1214]: Searching plugin music_service/soundcloud May 26 14:23:38 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: soundcloud , search May 26 14:23:38 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 9 error: Cancellation (0x8) May 26 14:23:38 music-hq-1 volumio[1214]: info: All search sources collected, pushing search results May 26 14:23:48 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 11 error: Cancellation (0x8) May 26 14:23:50 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioReplaceandPlayItems May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::ClearQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::serviceStop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::serviceStop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::clearPlayQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::addQueueItems May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::addQueueItems May 26 14:23:50 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1468923616 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1468923616 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1468923616 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1468923616 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPlay May 26 14:23:50 music-hq-1 volumio[1214]: verbose: UNSET VOLATILE: Service: soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Volatile state unset, stopping playback (if any)... May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"stop","albumart":"/albumart","uri":"","seek":20000,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:50 music-hq-1 volumio[1214]: verbose: STATE SERVICE {"status":"stop","albumart":"/albumart","uri":"","seek":20000,"duration":0,"service":"soundcloud","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:50 music-hq-1 volumio[1214]: verbose: CURRENT POSITION 1 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState stateService stop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::syncState currentStatus pause May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::play index 0 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::addQueueItems May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::addQueueItems May 26 14:23:50 music-hq-1 volumio[1214]: info: Preload queue cleared May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1593599932 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1593599932 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1593599932 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=243737844 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=243737844 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=243737844 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1752493200 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1752493200 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1752493200 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=37901324 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=37901324 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=37901324 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=665122520 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=665122520 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=665122520 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1825071204 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1825071204 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1825071204 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1518640234 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1518640234 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1518640234 May 26 14:23:50 music-hq-1 volumio[1214]: info: Adding Item to queue: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1664018289 May 26 14:23:50 music-hq-1 volumio[1214]: info: Exploding uri soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1664018289 in service soundcloud May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] explodeUri: soundcloud/tracks@search=discotek%20sancer@combinedSearch=1@title=SoundCloud%20tracks%20matching%20'discotek%20sancer'/track@trackId=1664018289 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::stPlaybackTimer May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::serviceStop May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 1 May 26 14:23:50 music-hq-1 volumio[1214]: info: ControllerMpd::stop May 26 14:23:50 music-hq-1 volumio[1214]: verbose: ControllerMpd::sendMpdCommand stop May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1593599932 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=243737844 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1752493200 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=37901324 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=665122520 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1825071204 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1518640234 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] getTrackUri(): soundcloud/track@trackId=1664018289 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::saveQueue May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::updateTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrackBlock May 26 14:23:50 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:50 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:50 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:50 music-hq-1 volumio[1214]: info: sendMpdCommand stop took 17 milliseconds May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::play index undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::startPlaybackTimer May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] clearAddPlayTrack: soundcloud/track@trackId=1468923616 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioGetState May 26 14:23:50 music-hq-1 volumio[1214]: info: CorePlayQueue::getTrack 0 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Stopping playback by current service... May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioStop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::stop May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Setting ourselves as the current service... May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) Push Volumio state: {"status":"pause","albumart":"https://i1.sndcdn.com/artworks-bStq1M5Bk69wQSmU-Nw8NvA-t500x500.jpg","uri":"soundcloud/track@trackId=1468923616","seek":20000,"duration":0,"service":"soundcloud","artist":"Techno Germany","album":"SoundCloud Track","name":"Premiere: SANCER - Discotek (Original Mix) [BLCKWRKS018]","title":"Premiere: SANCER - Discotek (Original Mix) [BLCKWRKS018]","trackType":"aac","samplerate":"160 kbps","isStreaming":false,"repeat":false,"repeatSingle":false,"random":null,"volume":31,"mute":false,"disableVolumeControl":false} May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::servicePushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:50 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:50 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 13 error: Cancellation (0x8) May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [af116918] http demux error: local stream 1 error: Cancellation (0x8) May 26 14:23:50 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b1adf7f8] adaptive demux: Changing stream format Unknown -> MP4 May 26 14:23:51 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b5e79f50] mp4 demux: Fragment sequence discontinuity detected 1 != 0 May 26 14:23:51 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b1adf7f8] http demux error: local stream 1 error: Cancellation (0x8) May 26 14:23:51 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b1adf7f8] http demux error: local stream 3 error: Cancellation (0x8) May 26 14:23:52 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b1adf7f8] http demux error: local stream 5 error: Cancellation (0x8) May 26 14:23:53 music-hq-1 volumio[1214]: info: [soundcloud] [vlc] (PID: 1753) [b1adf7f8] http demux error: local stream 7 error: Cancellation (0x8) May 26 14:23:54 music-hq-1 volumio[1214]: info: VolumeController::SetAlsaVolume25 May 26 14:23:54 music-hq-1 volumio[1214]: info: CoreStateMachine::pushState May 26 14:23:54 music-hq-1 volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 26 14:23:54 music-hq-1 volumio[1214]: info: CoreCommandRouter::volumioPushState May 26 14:23:54 music-hq-1 volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 May 26 14:23:54 music-hq-1 volumio[1214]: SPOTIFY: SPOTIFY VOLUME 31 May 26 14:23:54 music-hq-1 volumio[1214]: SPOTIFY: VOLUMIO VOLUME 25 May 26 14:23:54 music-hq-1 volumio[1214]: SPOTIFY: DELTA VOLUME ENOUGH: true May 26 14:23:54 music-hq-1 volumio[1214]: info: Setting Spotify Volume from Volumio: 25 May 26 14:23:56 music-hq-1 volumio[1214]: SPOTIFY: SETTING SPOTIFY VOLUME 25 May 26 14:23:56 music-hq-1 volumio[1214]: info: Sending Spotify command with payload to local API: /player/volume May 26 14:23:56 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:56+02:00" level=debug msg="update volume requested to 16383/65535" May 26 14:23:56 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:56+02:00" level=debug msg="renewing login5 access token" May 26 14:23:56 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:56+02:00" level=info msg="authenticated Login5" username="31************************nu" May 26 14:23:56 music-hq-1 volumio[1214]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 14:23:56 music-hq-1 volumio[1214]: Error: Operation timeout May 26 14:23:56 music-hq-1 volumio[1214]: at Timeout._onTimeout (/data/plugins/music_service/soundcloud/node_modules/volumio-ext-players/dist/vlc/VLCControl.js:28:20) May 26 14:23:56 music-hq-1 volumio[1214]: at listOnTimeout (node:internal/timers:573:17) May 26 14:23:56 music-hq-1 volumio[1214]: at process.processTimers (node:internal/timers:514:7) May 26 14:23:56 music-hq-1 volumio[1214]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 26 14:23:56 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:56+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 26 14:23:56 music-hq-1 go-librespot[1540]: time="2026-05-26T14:23:56+02:00" level=trace msg="emitting websocket event: volume" May 26 14:23:57 music-hq-1 sudo[953]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-26 14:22' May 26 14:23:57 music-hq-1 sudo[953]: 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"