-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2024-05-03 15:18:55 CEST. -- May 03 15:17:00 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:17:00 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/mytracks May 03 15:17:01 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:17:01 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/myartists May 03 15:17:01 volumio volumio[767]: info: Preload queue cleared May 03 15:17:05 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:17:05 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/playlists May 03 15:17:05 volumio volumio[767]: info: Preload queue cleared May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:7eMZXKjVjXQoYGK93cCPC7 May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:6yZAdQyPJtXjATvAT8ERQg May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:26b3oVLrRUaaybJulow9kz May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:7m7fHqG3R7jACPWWIx3Vk8 May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:0IVAlb0cFCH1cQ974iR1TU May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:0KRkgRkBa1fA4vJl8PMOTf May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:0FNPiAAdWdWaGr7JOnlKmi May 03 15:17:05 volumio volumio[767]: info: Preloading song: spotify:track:1f6CFsufAwVPHrcNdlACRQ May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:7eMZXKjVjXQoYGK93cCPC7 in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:7eMZXKjVjXQoYGK93cCPC7 May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:6yZAdQyPJtXjATvAT8ERQg in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:6yZAdQyPJtXjATvAT8ERQg May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:26b3oVLrRUaaybJulow9kz in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:26b3oVLrRUaaybJulow9kz May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:7m7fHqG3R7jACPWWIx3Vk8 in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:7m7fHqG3R7jACPWWIx3Vk8 May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:0IVAlb0cFCH1cQ974iR1TU in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:0IVAlb0cFCH1cQ974iR1TU May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:0KRkgRkBa1fA4vJl8PMOTf in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:0KRkgRkBa1fA4vJl8PMOTf May 03 15:17:05 volumio volumio[767]: (node:767) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'length' of null May 03 15:17:05 volumio volumio[767]: at ControllerSpotify._getAlbumArt (/data/plugins/music_service/spop/index.js:1106:54) May 03 15:17:05 volumio volumio[767]: at /data/plugins/music_service/spop/index.js:1439:44 May 03 15:17:05 volumio volumio[767]: at runMicrotasks () May 03 15:17:05 volumio volumio[767]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 03 15:17:05 volumio volumio[767]: (node:767) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 3) May 03 15:17:05 volumio volumio[767]: info: Exploding uri spotify:track:0FNPiAAdWdWaGr7JOnlKmi in service spop May 03 15:17:05 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:0FNPiAAdWdWaGr7JOnlKmi May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6yZAdQyPJtXjATvAT8ERQg","service":"spop","name":"Coolie High","artist":"Camp Lo","album":"Uptown Saturday Night","type":"song","duration":241,"albumart":"https://i.scdn.co/image/ab67616d0000b273a9e2d71c5d38c4c9418fb888","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7eMZXKjVjXQoYGK93cCPC7","service":"spop","name":"Listen (From the Motion Picture \"Dreamgirls\")","artist":"Beyoncé","album":"Dreamgirls (Music from the Motion Picture) [Deluxe Edition]","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273457a30c7050c5416171b4b6b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: info: Exploding uri spotify:track:1f6CFsufAwVPHrcNdlACRQ in service spop May 03 15:17:06 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:1f6CFsufAwVPHrcNdlACRQ May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:26b3oVLrRUaaybJulow9kz","service":"spop","name":"People","artist":"Libianca","album":"People","type":"song","duration":184,"albumart":"https://i.scdn.co/image/ab67616d0000b273fc342f95f117d48dbdde9735","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0KRkgRkBa1fA4vJl8PMOTf","service":"spop","name":"Stuck in My Ways (feat. 6LACK)","artist":"Phora","album":"Love Is Hell","type":"song","duration":238,"albumart":"https://i.scdn.co/image/ab67616d0000b273e59903549769d303b0918b4b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","service":"spop","name":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","type":"song","duration":223,"albumart":"https://i.scdn.co/image/ab67616d0000b27389b56f56323925d57b38944d","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1f6CFsufAwVPHrcNdlACRQ","service":"spop","name":"Don't Say Nuthin'","artist":"The Roots","album":"The Tipping Point","type":"song","duration":215,"albumart":"https://i.scdn.co/image/ab67616d0000b2738b49e8cdfda2e629a5ca2717","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7m7fHqG3R7jACPWWIx3Vk8","service":"spop","name":"Win or Lose","artist":"Mobb Deep","album":"Amerikaz Nightmare","type":"song","duration":193,"albumart":"https://i.scdn.co/image/ab67616d0000b273e562cd3a5b9b493c1f582ad0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:06 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0FNPiAAdWdWaGr7JOnlKmi","service":"spop","name":"Imagine","artist":"Snoop Dogg","album":"Tha Blue Carpet Treatment","type":"song","duration":282,"albumart":"https://i.scdn.co/image/ab67616d0000b2735a62c25459ad69981d5d09ef","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:17:10 volumio volumio[767]: info: Preload queue cleared May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::volumioReplaceandPlayItems May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::ClearQueue May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::stop May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::serviceStop May 03 15:17:10 volumio volumio[767]: info: Received STOP, but no service to execute it May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::clearPlayQueue May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::saveQueue May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::volumioPushQueue May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::addQueueItems May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::addQueueItems May 03 15:17:10 volumio volumio[767]: info: Preload queue cleared May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:7eMZXKjVjXQoYGK93cCPC7 May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:7eMZXKjVjXQoYGK93cCPC7 May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:6yZAdQyPJtXjATvAT8ERQg May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:6yZAdQyPJtXjATvAT8ERQg May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:26b3oVLrRUaaybJulow9kz May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:26b3oVLrRUaaybJulow9kz May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:7m7fHqG3R7jACPWWIx3Vk8 May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:7m7fHqG3R7jACPWWIx3Vk8 May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:0IVAlb0cFCH1cQ974iR1TU May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:0IVAlb0cFCH1cQ974iR1TU May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:0KRkgRkBa1fA4vJl8PMOTf May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:0KRkgRkBa1fA4vJl8PMOTf May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:0FNPiAAdWdWaGr7JOnlKmi May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:0FNPiAAdWdWaGr7JOnlKmi May 03 15:17:10 volumio volumio[767]: info: Adding Item to queue: spotify:track:1f6CFsufAwVPHrcNdlACRQ May 03 15:17:10 volumio volumio[767]: info: Using cached record of: spotify:track:1f6CFsufAwVPHrcNdlACRQ May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::volumioPushQueue May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::saveQueue May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::updateTrackBlock May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrackBlock May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::volumioPlay May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::play index 4 May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::stop May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::updateTrackBlock May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrackBlock May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::stPlaybackTimer May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::serviceStop May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:17:10 volumio volumio[767]: info: CoreCommandRouter::serviceStop May 03 15:17:10 volumio volumio[767]: info: Spotify Stop May 03 15:17:10 volumio volumio[767]: SPOTIFY: SPOTIFY STOP May 03 15:17:10 volumio volumio[767]: SPOTIFY: {"status":"pause","title":"If I Can't Have You","artist":"Shawn Mendes","album":"Shawn Mendes (Deluxe)","albumart":"https://i.scdn.co/image/ab67616d00001e02c820f033bd82bef4355d1563","uri":"spotify:track:2bT1PH7Cw3J9p3t7nlXCdh","trackType":"spotify","codec":"ogg","seek":69772,"duration":191,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":33,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 03 15:17:10 volumio volumio[767]: info: Sending Spotify command to local API: /player/pause May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::play index undefined May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:10 volumio volumio[767]: info: CoreStateMachine::startPlaybackTimer May 03 15:17:10 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:10 volumio volumio[767]: info: [1714742230636] ControllerSpotify::clearAddPlayTrack May 03 15:17:10 volumio volumio[767]: info: Sending Spotify command with payload to local API: /player/play May 03 15:17:10 volumio go-librespot[4037]: time="2024-05-03T15:17:10+02:00" level=debug msg="pause track at 71486ms" May 03 15:17:10 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:10 volumio go-librespot[4037]: time="2024-05-03T15:17:10+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="emitting websocket event: paused" May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2bT1PH7Cw3J9p3t7nlXCdh","play_origin":"playlist"}} May 03 15:17:11 volumio volumio[767]: info: Spotify is playing in volatile mode May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:11 volumio volumio[767]: SPOTIFY: UNSET VOLATILE May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"stop","position":0,"title":"Listen (From the Motion Picture \"Dreamgirls\")","artist":"Beyoncé","album":"Dreamgirls (Music from the Motion Picture) [Deluxe Edition]","albumart":"https://i.scdn.co/image/ab67616d0000b273457a30c7050c5416171b4b6b","uri":"spotify:track:7eMZXKjVjXQoYGK93cCPC7","trackType":"spotify","codec":"ogg","seek":0,"duration":219,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":33,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","updatedb":false,"volatile":false,"service":"spop"} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2bT1PH7Cw3J9p3t7nlXCdh","play_origin":"playlist"}} May 03 15:17:11 volumio volumio[767]: info: Spotify is playing in volatile mode May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:11 volumio volumio[767]: SPOTIFY: UNSET VOLATILE May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"stop","position":0,"title":"Listen (From the Motion Picture \"Dreamgirls\")","artist":"Beyoncé","album":"Dreamgirls (Music from the Motion Picture) [Deluxe Edition]","albumart":"https://i.scdn.co/image/ab67616d0000b273457a30c7050c5416171b4b6b","uri":"spotify:track:7eMZXKjVjXQoYGK93cCPC7","trackType":"spotify","codec":"ogg","seek":0,"duration":219,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":33,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","updatedb":false,"volatile":false,"service":"spop"} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2bT1PH7Cw3J9p3t7nlXCdh","play_origin":"playlist"}} May 03 15:17:11 volumio volumio[767]: info: Spotify is playing in volatile mode May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:17:11 volumio volumio[767]: SPOTIFY: UNSET VOLATILE May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"stop","position":0,"title":"Listen (From the Motion Picture \"Dreamgirls\")","artist":"Beyoncé","album":"Dreamgirls (Music from the Motion Picture) [Deluxe Edition]","albumart":"https://i.scdn.co/image/ab67616d0000b273457a30c7050c5416171b4b6b","uri":"spotify:track:7eMZXKjVjXQoYGK93cCPC7","trackType":"spotify","codec":"ogg","seek":0,"duration":219,"samplerate":"320 kbps","bitdepth":"16 bit","random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":33,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","updatedb":false,"volatile":false,"service":"spop"} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="loading track spotify:track:0IVAlb0cFCH1cQ974iR1TU (paused: false, position: 0ms)" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="emitting websocket event: will_play" May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:0IVAlb0cFCH1cQ974iR1TU" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="requested aes key for file 320bf641d44729e6d4b332af12f6953524635447, gid: 0IVAlb0cFCH1cQ974iR1TU" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="fetched first chunk of 19, total size is 9461816 bytes" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=info msg="loaded track \"Ms. Fat Booty\" (uri: spotify:track:0IVAlb0cFCH1cQ974iR1TU, paused: false, position: 0ms, duration: 223546ms)" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="fetched chunk 3/18, size: 524288" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="emitting websocket event: metadata" May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","name":"Ms. Fat Booty","artist_names":["Mos Def"],"album_name":"Black On Both Sides","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","position":0,"duration":223546,"release_date":"year:1999 month:10 day:12","track_number":4,"disc_number":1}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","name":"Ms. Fat Booty","artist_names":["Mos Def"],"album_name":"Black On Both Sides","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","position":0,"duration":223546,"release_date":"year:1999 month:10 day:12","track_number":4,"disc_number":1}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","name":"Ms. Fat Booty","artist_names":["Mos Def"],"album_name":"Black On Both Sides","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","position":0,"duration":223546,"release_date":"year:1999 month:10 day:12","track_number":4,"disc_number":1}} May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=trace msg="emitting websocket event: playing" May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="fetched chunk 2/18, size: 524288" May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:17:11 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:11 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:11 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:11 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:11 volumio go-librespot[4037]: time="2024-05-03T15:17:11+02:00" level=debug msg="fetched chunk 1/18, size: 524288" May 03 15:17:12 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:12 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:12 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:12 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:12 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:12 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:12 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:12 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:12 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:17:12 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","seek":0,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:12 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:12 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:12 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 May 03 15:17:17 volumio volumio[767]: info: VolumeController::SetAlsaVolume34 May 03 15:17:17 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:17 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:17 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:17 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 May 03 15:17:17 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 33 May 03 15:17:17 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 34 May 03 15:17:17 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: false May 03 15:17:18 volumio volumio[767]: info: May 03 15:17:18 volumio volumio[767]: ---------------------------- MPD announces state update: mixer May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::getState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand status May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand status took 2 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 03 15:17:18 volumio volumio[767]: error: Upnp client error: Error: This socket has been ended by the other party May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand playlistinfo took 2 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseTrackInfo May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:18 volumio volumio[767]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 03 15:17:18 volumio volumio[767]: info: ------------------------------ 15ms May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 May 03 15:17:18 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 33 May 03 15:17:18 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 34 May 03 15:17:18 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: false May 03 15:17:18 volumio volumio[767]: info: VolumeController::SetAlsaVolume36 May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 May 03 15:17:18 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 33 May 03 15:17:18 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 36 May 03 15:17:18 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true May 03 15:17:18 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 36 May 03 15:17:18 volumio volumio[767]: info: May 03 15:17:18 volumio volumio[767]: ---------------------------- MPD announces state update: mixer May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::getState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand status May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand status took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand playlistinfo took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseTrackInfo May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:18 volumio volumio[767]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 03 15:17:18 volumio volumio[767]: info: ------------------------------ 12ms May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 36 May 03 15:17:18 volumio volumio[767]: info: VolumeController::SetAlsaVolume37 May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 May 03 15:17:18 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 36 May 03 15:17:18 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 37 May 03 15:17:18 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: false May 03 15:17:18 volumio volumio[767]: info: May 03 15:17:18 volumio volumio[767]: ---------------------------- MPD announces state update: mixer May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::getState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand status May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand status took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand playlistinfo took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseTrackInfo May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:18 volumio volumio[767]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 03 15:17:18 volumio volumio[767]: info: ------------------------------ 12ms May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 37 May 03 15:17:18 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 36 May 03 15:17:18 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 37 May 03 15:17:18 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: false May 03 15:17:18 volumio volumio[767]: info: VolumeController::SetAlsaVolume41 May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 03 15:17:18 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 36 May 03 15:17:18 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 41 May 03 15:17:18 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true May 03 15:17:18 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 41 May 03 15:17:18 volumio volumio[767]: info: May 03 15:17:18 volumio volumio[767]: ---------------------------- MPD announces state update: mixer May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::getState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand status May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand status took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseState May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 03 15:17:18 volumio volumio[767]: info: sendMpdCommand playlistinfo took 1 milliseconds May 03 15:17:18 volumio volumio[767]: verbose: ControllerMpd::parseTrackInfo May 03 15:17:18 volumio volumio[767]: info: ControllerMpd::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:18 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:18 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:18 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:18 volumio volumio[767]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 03 15:17:18 volumio volumio[767]: info: ------------------------------ 13ms May 03 15:17:18 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 May 03 15:17:19 volumio volumio[767]: info: VolumeController::SetAlsaVolume44 May 03 15:17:19 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:19 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:17:19 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:19 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:17:19 volumio volumio[767]: SPOTIFY: SPOTIFY VOLUME 41 May 03 15:17:19 volumio volumio[767]: SPOTIFY: VOLUMIO VOLUME 44 May 03 15:17:19 volumio volumio[767]: SPOTIFY: DELTA VOLUME ENOUGH: true May 03 15:17:19 volumio volumio[767]: info: Setting Spotify Volume from Volumio: 44 May 03 15:17:19 volumio volumio[767]: info: May 03 15:17:19 volumio volumio[767]: ---------------------------- MPD announces state update: mixer May 03 15:17:19 volumio volumio[767]: info: ControllerMpd::getState May 03 15:17:19 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand status May 03 15:17:19 volumio volumio[767]: info: sendMpdCommand status took 2 milliseconds May 03 15:17:19 volumio volumio[767]: verbose: ControllerMpd::parseState May 03 15:17:19 volumio volumio[767]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 03 15:17:19 volumio volumio[767]: info: sendMpdCommand playlistinfo took 2 milliseconds May 03 15:17:19 volumio volumio[767]: verbose: ControllerMpd::parseTrackInfo May 03 15:17:19 volumio volumio[767]: info: ControllerMpd::pushState May 03 15:17:19 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:17:19 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:17:19 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:17:19 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:17:19 volumio volumio[767]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd May 03 15:17:19 volumio volumio[767]: info: ------------------------------ 14ms May 03 15:17:19 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:17:20 volumio volumio[767]: SPOTIFY: SETTING SPOTIFY VOLUME 44 May 03 15:17:20 volumio volumio[767]: info: Sending Spotify command with payload to local API: /player/volume May 03 15:17:20 volumio go-librespot[4037]: time="2024-05-03T15:17:20+02:00" level=debug msg="update volume to 28835/65535" May 03 15:17:20 volumio go-librespot[4037]: time="2024-05-03T15:17:20+02:00" level=debug msg="put connect state because VOLUME_CHANGED" May 03 15:17:20 volumio go-librespot[4037]: time="2024-05-03T15:17:20+02:00" level=trace msg="emitting websocket event: volume" May 03 15:17:20 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":44,"max":100}} May 03 15:17:20 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 44 May 03 15:17:20 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":44,"max":100}} May 03 15:17:20 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 44 May 03 15:17:20 volumio volumio[767]: SPOTIFY: received: {"type":"volume","data":{"value":44,"max":100}} May 03 15:17:20 volumio volumio[767]: SPOTIFY: RECEIVED SPOTIFY VOLUME 44 May 03 15:17:23 volumio go-librespot[4037]: time="2024-05-03T15:17:23+02:00" level=debug msg="fetched chunk 4/18, size: 524288" May 03 15:17:36 volumio go-librespot[4037]: time="2024-05-03T15:17:36+02:00" level=debug msg="fetched chunk 5/18, size: 524288" May 03 15:17:40 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:17:40 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/category/0JQ5DAqbMKFQ00XGBls6ym May 03 15:17:41 volumio volumio[767]: info: Preload queue cleared May 03 15:17:48 volumio go-librespot[4037]: time="2024-05-03T15:17:48+02:00" level=debug msg="fetched chunk 6/18, size: 524288" May 03 15:18:00 volumio go-librespot[4037]: time="2024-05-03T15:18:00+02:00" level=debug msg="fetched chunk 7/18, size: 524288" May 03 15:18:00 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:18:00 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/playlists May 03 15:18:01 volumio volumio[767]: (node:767) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'length' of null May 03 15:18:01 volumio volumio[767]: at ControllerSpotify._getAlbumArt (/data/plugins/music_service/spop/index.js:1106:54) May 03 15:18:01 volumio volumio[767]: at /data/plugins/music_service/spop/index.js:1439:44 May 03 15:18:01 volumio volumio[767]: at runMicrotasks () May 03 15:18:01 volumio volumio[767]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 03 15:18:01 volumio volumio[767]: (node:767) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4) May 03 15:18:13 volumio go-librespot[4037]: time="2024-05-03T15:18:13+02:00" level=debug msg="fetched chunk 8/18, size: 524288" May 03 15:18:19 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:18:19 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify/myalbums May 03 15:18:20 volumio volumio[767]: info: Preload queue cleared May 03 15:18:24 volumio go-librespot[4037]: time="2024-05-03T15:18:24+02:00" level=debug msg="fetched chunk 9/18, size: 524288" May 03 15:18:25 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri May 03 15:18:25 volumio volumio[767]: info: In handleBrowseUri, curUri=spotify:album:7aWNHIpUIFnlu2UhOWqooG May 03 15:18:26 volumio volumio[767]: info: Preload queue cleared May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:1Wj0cZxHcg39CCtbpsBAlF May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:3J07OCYrIQuSuWLQbeFzZa May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:4mnjagpaCTWFLqiRMHbFAm May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:3OqAfT7j0JP6uISeiUIN62 May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:2IRrP0ok87Ny6X1lfoekYk May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:3h4HlcmWdexWJ6SSyZG67E May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:5OycoZIedX9m0EAVC73SC9 May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:3u3Oh9jr7CzrxlbP2ixhsn May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:58IXrujjBzitzoFNFzn1c4 May 03 15:18:26 volumio volumio[767]: info: Preloading song: spotify:track:73oGQQDVLvNejmb3YMx0ZC May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:1Wj0cZxHcg39CCtbpsBAlF in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:1Wj0cZxHcg39CCtbpsBAlF May 03 15:18:26 volumio volumio[767]: info: No valid Plugin REST Endpoint May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:3J07OCYrIQuSuWLQbeFzZa in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:3J07OCYrIQuSuWLQbeFzZa May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:4mnjagpaCTWFLqiRMHbFAm in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:4mnjagpaCTWFLqiRMHbFAm May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:3OqAfT7j0JP6uISeiUIN62 in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:3OqAfT7j0JP6uISeiUIN62 May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:2IRrP0ok87Ny6X1lfoekYk in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:2IRrP0ok87Ny6X1lfoekYk May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:3h4HlcmWdexWJ6SSyZG67E in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:3h4HlcmWdexWJ6SSyZG67E May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:5OycoZIedX9m0EAVC73SC9 in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:5OycoZIedX9m0EAVC73SC9 May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:3u3Oh9jr7CzrxlbP2ixhsn in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:3u3Oh9jr7CzrxlbP2ixhsn May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","service":"spop","name":"Act Up (with Jon Batiste)","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":218,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:58IXrujjBzitzoFNFzn1c4 in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:58IXrujjBzitzoFNFzn1c4 May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3J07OCYrIQuSuWLQbeFzZa","service":"spop","name":"Birds","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":165,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: info: Exploding uri spotify:track:73oGQQDVLvNejmb3YMx0ZC in service spop May 03 15:18:26 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:track:73oGQQDVLvNejmb3YMx0ZC May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3OqAfT7j0JP6uISeiUIN62","service":"spop","name":"Kat Food","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":286,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2IRrP0ok87Ny6X1lfoekYk","service":"spop","name":"Tuxedo (with euro)","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":190,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4mnjagpaCTWFLqiRMHbFAm","service":"spop","name":"Slip","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":210,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3h4HlcmWdexWJ6SSyZG67E","service":"spop","name":"To The Bank","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":132,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5OycoZIedX9m0EAVC73SC9","service":"spop","name":"Chanel No. 5 (with Fousheé)","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3u3Oh9jr7CzrxlbP2ixhsn","service":"spop","name":"No New Bitches","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":158,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:58IXrujjBzitzoFNFzn1c4","service":"spop","name":"Tity Boi","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":314,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:26 volumio volumio[767]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:73oGQQDVLvNejmb3YMx0ZC","service":"spop","name":"Good Morning","artist":"Lil Wayne","album":"Tha Fix Before Tha VI","type":"song","duration":109,"albumart":"https://i.scdn.co/image/ab67616d0000b27322bc4bb1bed9da44b798857b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] May 03 15:18:35 volumio volumio[767]: info: Preload queue cleared May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::volumioReplaceandPlayItems May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::ClearQueue May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::stop May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::serviceStop May 03 15:18:35 volumio volumio[767]: info: Received STOP, but no service to execute it May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::clearPlayQueue May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::saveQueue May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::volumioPushQueue May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::addQueueItems May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::addQueueItems May 03 15:18:35 volumio volumio[767]: info: Preload queue cleared May 03 15:18:35 volumio volumio[767]: info: Adding Item to queue: spotify:album:7aWNHIpUIFnlu2UhOWqooG May 03 15:18:35 volumio volumio[767]: info: Exploding uri spotify:album:7aWNHIpUIFnlu2UhOWqooG in service spop May 03 15:18:35 volumio volumio[767]: SPOTIFY: EXPLODING URI:spotify:album:7aWNHIpUIFnlu2UhOWqooG May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::volumioPushQueue May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::saveQueue May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::updateTrackBlock May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::getTrackBlock May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::volumioPlay May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::play index 0 May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::stop May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::stPlaybackTimer May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::updateTrackBlock May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::getTrackBlock May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::serviceStop May 03 15:18:35 volumio volumio[767]: info: CorePlayQueue::getTrack 4 May 03 15:18:35 volumio volumio[767]: info: CoreCommandRouter::serviceStop May 03 15:18:35 volumio volumio[767]: info: Spotify Stop May 03 15:18:35 volumio volumio[767]: SPOTIFY: SPOTIFY STOP May 03 15:18:35 volumio volumio[767]: SPOTIFY: {"status":"play","title":"Ms. Fat Booty","artist":"Mos Def","album":"Black On Both Sides","albumart":"https://i.scdn.co/image/ab67616d00001e0289b56f56323925d57b38944d","uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","trackType":"spotify","codec":"ogg","seek":7000,"duration":223,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":44,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 03 15:18:35 volumio volumio[767]: info: Sending Spotify command to local API: /player/pause May 03 15:18:35 volumio volumio[767]: info: CoreStateMachine::play index undefined May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::setConsumeUpdateService undefined May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::startPlaybackTimer May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: [1714742316001] ControllerSpotify::clearAddPlayTrack May 03 15:18:36 volumio volumio[767]: info: Sending Spotify command with payload to local API: /player/play May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="pause track at 84735ms" May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="emitting websocket event: paused" May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService pause May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus stop May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService pause May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus stop May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0IVAlb0cFCH1cQ974iR1TU","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService pause May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus stop May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="loading track spotify:track:1Wj0cZxHcg39CCtbpsBAlF (paused: false, position: 0ms)" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="emitting websocket event: will_play" May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","play_origin":"go-librespot"}} May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1Wj0cZxHcg39CCtbpsBAlF" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="requested aes key for file be0d727d8f3cb762629c7d3bd5be85af1a8365c8, gid: 1Wj0cZxHcg39CCtbpsBAlF" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="fetched first chunk of 19, total size is 9782804 bytes" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=info msg="loaded track \"Act Up (with Jon Batiste)\" (uri: spotify:track:1Wj0cZxHcg39CCtbpsBAlF, paused: false, position: 0ms, duration: 218620ms)" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="fetched chunk 3/18, size: 524288" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="fetched chunk 1/18, size: 524288" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="emitting websocket event: metadata" May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","name":"Act Up (with Jon Batiste)","artist_names":["Lil Wayne","Jon Batiste"],"album_name":"Tha Fix Before Tha VI","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","position":0,"duration":218620,"release_date":"year:2023 month:9 day:29","track_number":1,"disc_number":1}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","name":"Act Up (with Jon Batiste)","artist_names":["Lil Wayne","Jon Batiste"],"album_name":"Tha Fix Before Tha VI","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","position":0,"duration":218620,"release_date":"year:2023 month:9 day:29","track_number":1,"disc_number":1}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","name":"Act Up (with Jon Batiste)","artist_names":["Lil Wayne","Jon Batiste"],"album_name":"Tha Fix Before Tha VI","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","position":0,"duration":218620,"release_date":"year:2023 month:9 day:29","track_number":1,"disc_number":1}} May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="fetched chunk 2/18, size: 524288" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 03 15:18:36 volumio go-librespot[4037]: time="2024-05-03T15:18:36+02:00" level=trace msg="emitting websocket event: playing" May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus stop May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus play May 03 15:18:36 volumio volumio[767]: info: Received an update from plugin. extracting info from payload May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","play_origin":"go-librespot"}} May 03 15:18:36 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:36 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:36 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus play May 03 15:18:36 volumio volumio[767]: info: Received an update from plugin. extracting info from payload May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:36 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:36 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:36 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:37 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus play May 03 15:18:37 volumio volumio[767]: info: Received an update from plugin. extracting info from payload May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:37 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus play May 03 15:18:37 volumio volumio[767]: info: Received an update from plugin. extracting info from payload May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: SPOTIFY: PUSH STATE SPOTIFY May 03 15:18:37 volumio volumio[767]: SPOTIFY: {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::servicePushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Act Up (with Jon Batiste)","artist":"Lil Wayne, Jon Batiste","album":"Tha Fix Before Tha VI","albumart":"https://i.scdn.co/image/ab67616d00001e0222bc4bb1bed9da44b798857b","uri":"spotify:track:1Wj0cZxHcg39CCtbpsBAlF","trackType":"spotify","seek":0,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} May 03 15:18:37 volumio volumio[767]: verbose: CURRENT POSITION 0 May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState stateService play May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::syncState currentStatus play May 03 15:18:37 volumio volumio[767]: info: Received an update from plugin. extracting info from payload May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: info: CoreStateMachine::pushState May 03 15:18:37 volumio volumio[767]: info: CorePlayQueue::getTrack 0 May 03 15:18:37 volumio volumio[767]: info: CoreCommandRouter::volumioPushState May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:37 volumio volumio[767]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 May 03 15:18:46 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 03 15:18:46 volumio volumio[767]: info: Preload queue cleared May 03 15:18:48 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 03 15:18:48 volumio volumio[767]: info: Preload queue cleared May 03 15:18:49 volumio go-librespot[4037]: time="2024-05-03T15:18:49+02:00" level=debug msg="fetched chunk 4/18, size: 524288" May 03 15:18:52 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 03 15:18:53 volumio volumio[767]: info: Preload queue cleared May 03 15:18:54 volumio volumio[767]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 03 15:18:54 volumio volumio[767]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 03 15:18:54 volumio volumio[767]: TypeError: Cannot read property 'length' of undefined May 03 15:18:54 volumio volumio[767]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 03 15:18:54 volumio volumio[767]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 03 15:18:54 volumio volumio[767]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 03 15:18:54 volumio volumio[767]: at Parser.emit (events.js:315:20) May 03 15:18:54 volumio volumio[767]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 03 15:18:54 volumio volumio[767]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 03 15:18:54 volumio volumio[767]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 03 15:18:54 volumio volumio[767]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 03 15:18:54 volumio volumio[767]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 03 15:18:54 volumio volumio[767]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 03 15:18:54 volumio volumio[767]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 03 15:18:54 volumio volumio[767]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 03 15:18:54 volumio volumio[767]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 03 15:18:54 volumio volumio[767]: at IncomingMessage.emit (events.js:327:22) May 03 15:18:54 volumio volumio[767]: at endReadableNT (internal/streams/readable.js:1327:12) May 03 15:18:54 volumio volumio[767]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 03 15:18:54 volumio volumio[767]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 03 15:18:55 volumio sudo[4691]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-03 15:17 May 03 15:18:55 volumio sudo[4691]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"