-- Logs begin at Sat 2025-06-07 19:34:33 +07, end at Sat 2025-06-07 19:51:59 +07. -- Jun 07 19:50:11 volumio go-librespot[1781]: time="2025-06-07T19:50:11+07:00" level=debug msg="fetched chunk 13/17, size: 524288" uri="spotify:track:37pLS8UMAnxlDMRihU24GR" Jun 07 19:50:15 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:50:15 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:19 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:50:20 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:22 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:50:23 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106746 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106747 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106750 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106752 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106766 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106767 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106768 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106775 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106780 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106781 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106782 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106783 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106784 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106785 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106786 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106787 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106788 Jun 07 19:50:23 volumio volumio[1108]: info: Preloading song: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106789 Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106746 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106747 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106750 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106752 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106766 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106767 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106768 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106775 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106780 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106781 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106782 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106783 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106784 in service upnp_browser Jun 07 19:50:23 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106785 in service upnp_browser Jun 07 19:50:24 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106786 in service upnp_browser Jun 07 19:50:24 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106787 in service upnp_browser Jun 07 19:50:24 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:24 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106788 in service upnp_browser Jun 07 19:50:24 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:24 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106789 in service upnp_browser Jun 07 19:50:24 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:26 volumio go-librespot[1781]: time="2025-06-07T19:50:26+07:00" level=debug msg="fetched chunk 14/17, size: 524288" uri="spotify:track:37pLS8UMAnxlDMRihU24GR" Jun 07 19:50:27 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 07 19:50:27 volumio volumio[1108]: info: CoreStateMachine::ClearQueue Jun 07 19:50:27 volumio volumio[1108]: info: CoreStateMachine::stop Jun 07 19:50:27 volumio volumio[1108]: info: CoreStateMachine::serviceStop Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::serviceStop Jun 07 19:50:27 volumio volumio[1108]: info: Spotify Stop Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: SPOTIFY STOP Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: {"status":"play","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","codec":"ogg","seek":87000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 07 19:50:27 volumio volumio[1108]: info: Sending Spotify command to local API: /player/pause Jun 07 19:50:27 volumio volumio[1108]: info: CorePlayQueue::clearPlayQueue Jun 07 19:50:27 volumio volumio[1108]: info: CorePlayQueue::saveQueue Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::volumioPushQueue Jun 07 19:50:27 volumio volumio[1108]: info: CoreStateMachine::addQueueItems Jun 07 19:50:27 volumio volumio[1108]: info: CorePlayQueue::addQueueItems Jun 07 19:50:27 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:27 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 Jun 07 19:50:27 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 in service upnp_browser Jun 07 19:50:27 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:27 volumio go-librespot[1781]: time="2025-06-07T19:50:27+07:00" level=debug msg="pause track at 151893ms" Jun 07 19:50:27 volumio go-librespot[1781]: time="2025-06-07T19:50:27+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:27 volumio go-librespot[1781]: time="2025-06-07T19:50:27+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:27 volumio go-librespot[1781]: time="2025-06-07T19:50:27+07:00" level=trace msg="emitting websocket event: paused" Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","play_origin":"artist"}} Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: PUSH STATE SPOTIFY Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: {"status":"pause","service":"spop","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::servicePushState Jun 07 19:50:27 volumio volumio[1108]: info: CoreStateMachine::pushState Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 07 19:50:27 volumio volumio[1108]: info: CoreCommandRouter::volumioPushState Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: SPOTIFY VOLUME 99 Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: VOLUMIO VOLUME 100 Jun 07 19:50:27 volumio volumio[1108]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 07 19:50:33 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:33 volumio volumio[1108]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 07 19:50:33 volumio volumio[1108]: info: CoreStateMachine::ClearQueue Jun 07 19:50:33 volumio volumio[1108]: info: CoreStateMachine::stop Jun 07 19:50:33 volumio volumio[1108]: info: CoreStateMachine::serviceStop Jun 07 19:50:33 volumio volumio[1108]: info: CoreCommandRouter::serviceStop Jun 07 19:50:33 volumio volumio[1108]: info: Spotify Stop Jun 07 19:50:33 volumio volumio[1108]: SPOTIFY: SPOTIFY STOP Jun 07 19:50:33 volumio volumio[1108]: SPOTIFY: {"status":"pause","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","codec":"ogg","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 07 19:50:33 volumio volumio[1108]: info: Sending Spotify command to local API: /player/pause Jun 07 19:50:33 volumio volumio[1108]: info: CorePlayQueue::clearPlayQueue Jun 07 19:50:33 volumio volumio[1108]: info: CorePlayQueue::saveQueue Jun 07 19:50:33 volumio volumio[1108]: info: CoreCommandRouter::volumioPushQueue Jun 07 19:50:33 volumio volumio[1108]: info: CoreStateMachine::addQueueItems Jun 07 19:50:33 volumio volumio[1108]: info: CorePlayQueue::addQueueItems Jun 07 19:50:33 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:33 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 Jun 07 19:50:33 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 in service upnp_browser Jun 07 19:50:33 volumio go-librespot[1781]: time="2025-06-07T19:50:33+07:00" level=debug msg="pause track at 152396ms" Jun 07 19:50:33 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:33 volumio go-librespot[1781]: time="2025-06-07T19:50:33+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:33 volumio go-librespot[1781]: time="2025-06-07T19:50:33+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:33 volumio go-librespot[1781]: time="2025-06-07T19:50:33+07:00" level=trace msg="emitting websocket event: paused" Jun 07 19:50:33 volumio volumio[1108]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","play_origin":"artist"}} Jun 07 19:50:33 volumio volumio[1108]: SPOTIFY: PUSH STATE SPOTIFY Jun 07 19:50:33 volumio volumio[1108]: SPOTIFY: {"status":"pause","service":"spop","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 07 19:50:33 volumio volumio[1108]: info: CoreCommandRouter::servicePushState Jun 07 19:50:33 volumio volumio[1108]: info: CoreStateMachine::pushState Jun 07 19:50:33 volumio volumio[1108]: info: CoreCommandRouter::volumioPushState Jun 07 19:50:34 volumio volumio[1108]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 07 19:50:34 volumio volumio[1108]: SPOTIFY: SPOTIFY VOLUME 99 Jun 07 19:50:34 volumio volumio[1108]: SPOTIFY: VOLUMIO VOLUME 100 Jun 07 19:50:34 volumio volumio[1108]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 07 19:50:36 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:36 volumio volumio[1108]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 07 19:50:36 volumio volumio[1108]: info: CoreStateMachine::ClearQueue Jun 07 19:50:36 volumio volumio[1108]: info: CoreStateMachine::stop Jun 07 19:50:36 volumio volumio[1108]: info: CoreStateMachine::serviceStop Jun 07 19:50:36 volumio volumio[1108]: info: CoreCommandRouter::serviceStop Jun 07 19:50:36 volumio volumio[1108]: info: Spotify Stop Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: SPOTIFY STOP Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: {"status":"pause","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","codec":"ogg","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 07 19:50:36 volumio volumio[1108]: info: Sending Spotify command to local API: /player/pause Jun 07 19:50:36 volumio volumio[1108]: info: CorePlayQueue::clearPlayQueue Jun 07 19:50:36 volumio volumio[1108]: info: CorePlayQueue::saveQueue Jun 07 19:50:36 volumio volumio[1108]: info: CoreCommandRouter::volumioPushQueue Jun 07 19:50:36 volumio volumio[1108]: info: CoreStateMachine::addQueueItems Jun 07 19:50:36 volumio volumio[1108]: info: CorePlayQueue::addQueueItems Jun 07 19:50:36 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:36 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 Jun 07 19:50:36 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 in service upnp_browser Jun 07 19:50:36 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 Jun 07 19:50:36 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 in service upnp_browser Jun 07 19:50:36 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 Jun 07 19:50:36 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 in service upnp_browser Jun 07 19:50:36 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 Jun 07 19:50:36 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 in service upnp_browser Jun 07 19:50:36 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 Jun 07 19:50:36 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 in service upnp_browser Jun 07 19:50:36 volumio go-librespot[1781]: time="2025-06-07T19:50:36+07:00" level=debug msg="pause track at 152396ms" Jun 07 19:50:36 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:36 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:36 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:36 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:36 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:36 volumio go-librespot[1781]: time="2025-06-07T19:50:36+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:36 volumio go-librespot[1781]: time="2025-06-07T19:50:36+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:36 volumio go-librespot[1781]: time="2025-06-07T19:50:36+07:00" level=trace msg="emitting websocket event: paused" Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","play_origin":"artist"}} Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: PUSH STATE SPOTIFY Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: {"status":"pause","service":"spop","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 07 19:50:36 volumio volumio[1108]: info: CoreCommandRouter::servicePushState Jun 07 19:50:36 volumio volumio[1108]: info: CoreStateMachine::pushState Jun 07 19:50:36 volumio volumio[1108]: info: CoreCommandRouter::volumioPushState Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: SPOTIFY VOLUME 99 Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: VOLUMIO VOLUME 100 Jun 07 19:50:36 volumio volumio[1108]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 07 19:50:38 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:38 volumio volumio[1108]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 07 19:50:38 volumio volumio[1108]: info: CoreStateMachine::ClearQueue Jun 07 19:50:38 volumio volumio[1108]: info: CoreStateMachine::stop Jun 07 19:50:38 volumio volumio[1108]: info: CoreStateMachine::serviceStop Jun 07 19:50:38 volumio volumio[1108]: info: CoreCommandRouter::serviceStop Jun 07 19:50:38 volumio volumio[1108]: info: Spotify Stop Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: SPOTIFY STOP Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: {"status":"pause","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","codec":"ogg","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 07 19:50:38 volumio volumio[1108]: info: Sending Spotify command to local API: /player/pause Jun 07 19:50:38 volumio volumio[1108]: info: CorePlayQueue::clearPlayQueue Jun 07 19:50:38 volumio volumio[1108]: info: CorePlayQueue::saveQueue Jun 07 19:50:38 volumio volumio[1108]: info: CoreCommandRouter::volumioPushQueue Jun 07 19:50:38 volumio volumio[1108]: info: CoreStateMachine::addQueueItems Jun 07 19:50:38 volumio volumio[1108]: info: CorePlayQueue::addQueueItems Jun 07 19:50:38 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:50:38 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 Jun 07 19:50:38 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106736 in service upnp_browser Jun 07 19:50:38 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 Jun 07 19:50:38 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106737 in service upnp_browser Jun 07 19:50:38 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 Jun 07 19:50:38 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106739 in service upnp_browser Jun 07 19:50:38 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 Jun 07 19:50:38 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106740 in service upnp_browser Jun 07 19:50:38 volumio volumio[1108]: info: Adding Item to queue: upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 Jun 07 19:50:38 volumio volumio[1108]: info: Exploding uri upnp/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_32ab985b-106744 in service upnp_browser Jun 07 19:50:38 volumio go-librespot[1781]: time="2025-06-07T19:50:38+07:00" level=debug msg="pause track at 152396ms" Jun 07 19:50:38 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:38 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:38 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:38 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:38 volumio volumio[1108]: error: Did not get expected response from server:{"Envelope":{"$":{"xmlns:SOAP-ENV":"http://schemas.xmlsoap.org/soap/envelope/","SOAP-ENV:encodingStyle":"http://schemas.xmlsoap.org/soap/encoding/"},"Body":[{"Fault":[{"faultcode":[{"_":"SOAP-ENV:Client"}],"faultstring":[{"_":"UPnPError"}],"detail":[{"UPnPError":[{"$":{"xmlns:u":"urn:schemas-upnp-org:control-1-0"},"errorCode":[{"_":"720"}],"errorDescription":[{"_":"Cannot process the request"}]}]}]}]}]}} Jun 07 19:50:38 volumio go-librespot[1781]: time="2025-06-07T19:50:38+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:38 volumio go-librespot[1781]: time="2025-06-07T19:50:38+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:50:38 volumio go-librespot[1781]: time="2025-06-07T19:50:38+07:00" level=trace msg="emitting websocket event: paused" Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","play_origin":"artist"}} Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: PUSH STATE SPOTIFY Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: {"status":"pause","service":"spop","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 07 19:50:38 volumio volumio[1108]: info: CoreCommandRouter::servicePushState Jun 07 19:50:38 volumio volumio[1108]: info: CoreStateMachine::pushState Jun 07 19:50:38 volumio volumio[1108]: info: CoreCommandRouter::volumioPushState Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: SPOTIFY VOLUME 99 Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: VOLUMIO VOLUME 100 Jun 07 19:50:38 volumio volumio[1108]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 07 19:51:19 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:21 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:21 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:23 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:51:23 volumio volumio[1108]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 07 19:51:23 volumio volumio[1108]: info: CoreStateMachine::ClearQueue Jun 07 19:51:23 volumio volumio[1108]: info: CoreStateMachine::stop Jun 07 19:51:23 volumio volumio[1108]: info: CoreStateMachine::serviceStop Jun 07 19:51:23 volumio volumio[1108]: info: CoreCommandRouter::serviceStop Jun 07 19:51:23 volumio volumio[1108]: info: Spotify Stop Jun 07 19:51:23 volumio volumio[1108]: SPOTIFY: SPOTIFY STOP Jun 07 19:51:23 volumio volumio[1108]: SPOTIFY: {"status":"pause","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","codec":"ogg","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 07 19:51:23 volumio volumio[1108]: info: Sending Spotify command to local API: /player/pause Jun 07 19:51:23 volumio volumio[1108]: info: CorePlayQueue::clearPlayQueue Jun 07 19:51:23 volumio volumio[1108]: info: CorePlayQueue::saveQueue Jun 07 19:51:23 volumio volumio[1108]: info: CoreCommandRouter::volumioPushQueue Jun 07 19:51:23 volumio volumio[1108]: info: CoreStateMachine::addQueueItems Jun 07 19:51:23 volumio volumio[1108]: info: CorePlayQueue::addQueueItems Jun 07 19:51:23 volumio volumio[1108]: info: Preload queue cleared Jun 07 19:51:23 volumio volumio[1108]: info: Adding Item to queue: upnp/folder/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_6d2aa49e Jun 07 19:51:23 volumio volumio[1108]: info: Exploding uri upnp/folder/http://192.168.1.133:2869/upnphost/udhisapi.dll?control=uuid:4a55e351-e0c0-4a7f-ae06-ec513555fbe5+urn:upnp-org:serviceId:ContentDirectory@14_b4a13d53_50c00fb6_6d2aa49e in service upnp_browser Jun 07 19:51:23 volumio go-librespot[1781]: time="2025-06-07T19:51:23+07:00" level=debug msg="pause track at 152396ms" Jun 07 19:51:23 volumio go-librespot[1781]: time="2025-06-07T19:51:23+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:51:24 volumio go-librespot[1781]: time="2025-06-07T19:51:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 07 19:51:24 volumio go-librespot[1781]: time="2025-06-07T19:51:24+07:00" level=trace msg="emitting websocket event: paused" Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","play_origin":"artist"}} Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: PUSH STATE SPOTIFY Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: {"status":"pause","service":"spop","title":"Il Ragazzo Della Via Gluck","artist":"Adriano Celentano","album":"Le Robe Che Ha Detto Adriano","albumart":"https://i.scdn.co/image/ab67616d00001e02255ceb75f1cb214815c7b5b4","uri":"spotify:track:37pLS8UMAnxlDMRihU24GR","trackType":"spotify","seek":152000,"duration":255,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 07 19:51:24 volumio volumio[1108]: info: CoreCommandRouter::servicePushState Jun 07 19:51:24 volumio volumio[1108]: info: CoreStateMachine::pushState Jun 07 19:51:24 volumio volumio[1108]: info: CoreCommandRouter::volumioPushState Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: SPOTIFY VOLUME 99 Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: VOLUMIO VOLUME 100 Jun 07 19:51:24 volumio volumio[1108]: SPOTIFY: DELTA VOLUME ENOUGH: false Jun 07 19:51:30 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:33 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:36 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:38 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:40 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:44 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:45 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:52 volumio volumio[1108]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jun 07 19:51:58 volumio volumio[1108]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 07 19:51:58 volumio volumio[1108]: TypeError: Cannot read property 'length' of undefined Jun 07 19:51:58 volumio volumio[1108]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jun 07 19:51:58 volumio volumio[1108]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jun 07 19:51:58 volumio volumio[1108]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jun 07 19:51:58 volumio volumio[1108]: at Parser.emit (events.js:400:28) Jun 07 19:51:58 volumio volumio[1108]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jun 07 19:51:58 volumio volumio[1108]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jun 07 19:51:58 volumio volumio[1108]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jun 07 19:51:58 volumio volumio[1108]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jun 07 19:51:58 volumio volumio[1108]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jun 07 19:51:58 volumio volumio[1108]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jun 07 19:51:58 volumio volumio[1108]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jun 07 19:51:58 volumio volumio[1108]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jun 07 19:51:58 volumio volumio[1108]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jun 07 19:51:58 volumio volumio[1108]: at IncomingMessage.emit (events.js:412:35) Jun 07 19:51:58 volumio volumio[1108]: at endReadableNT (internal/streams/readable.js:1333:12) Jun 07 19:51:58 volumio volumio[1108]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jun 07 19:51:58 volumio volumio[1108]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 07 19:51:59 volumio sudo[4653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-07 19:50 Jun 07 19:51:59 volumio sudo[4653]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:07:11 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="dc77d77f02ef88ea816c3d31de871e8f"