-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-07-21 09:34:44 CEST. --
Jul 21 09:33:03 volumio volumio[958]: info: VolumeController::SetAlsaVolume+
Jul 21 09:33:03 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:03 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:03 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:03 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:03 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Jul 21 09:33:03 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 24
Jul 21 09:33:03 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 25
Jul 21 09:33:03 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:04 volumio volumio[958]: info: VolumeController::SetAlsaVolume+
Jul 21 09:33:04 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:04 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:04 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:04 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:04 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 26
Jul 21 09:33:04 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 24
Jul 21 09:33:04 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 26
Jul 21 09:33:04 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: true
Jul 21 09:33:04 volumio volumio[958]: info: Setting Spotify Volume from Volumio: 26
Jul 21 09:33:05 volumio volumio[958]: info: VolumeController::SetAlsaVolume+
Jul 21 09:33:05 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:05 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:05 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:05 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27
Jul 21 09:33:05 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 26
Jul 21 09:33:05 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 27
Jul 21 09:33:05 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: SETTING SPOTIFY VOLUME 26
Jul 21 09:33:06 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/volume
Jul 21 09:33:06 volumio go-librespot[1266]: time="2024-07-21T09:33:06+02:00" level=debug msg="update volume to 17039/65535"
Jul 21 09:33:06 volumio go-librespot[1266]: time="2024-07-21T09:33:06+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Jul 21 09:33:06 volumio go-librespot[1266]: time="2024-07-21T09:33:06+02:00" level=trace msg="emitting websocket event: volume"
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: received: {"type":"volume","data":{"value":26,"max":100}}
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: RECEIVED SPOTIFY VOLUME 26
Jul 21 09:33:06 volumio volumio[958]: info: VolumeController::SetAlsaVolume+
Jul 21 09:33:06 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:06 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:06 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 28
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 26
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 28
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: true
Jul 21 09:33:06 volumio volumio[958]: info: Setting Spotify Volume from Volumio: 28
Jul 21 09:33:06 volumio volumio[958]: info: VolumeController::SetAlsaVolume+
Jul 21 09:33:06 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:06 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:06 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:33:06 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:06 volumio volumio[958]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 13
Jul 21 09:33:06 volumio volumio[958]: info: CoreCommandRouter::volumioGetState
Jul 21 09:33:06 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:07 volumio volumio[958]: SPOTIFY: SETTING SPOTIFY VOLUME 28
Jul 21 09:33:07 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/volume
Jul 21 09:33:07 volumio go-librespot[1266]: time="2024-07-21T09:33:07+02:00" level=debug msg="update volume to 18349/65535"
Jul 21 09:33:07 volumio go-librespot[1266]: time="2024-07-21T09:33:07+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Jul 21 09:33:07 volumio go-librespot[1266]: time="2024-07-21T09:33:07+02:00" level=trace msg="emitting websocket event: volume"
Jul 21 09:33:07 volumio volumio[958]: SPOTIFY: received: {"type":"volume","data":{"value":28,"max":100}}
Jul 21 09:33:07 volumio volumio[958]: SPOTIFY: RECEIVED SPOTIFY VOLUME 28
Jul 21 09:33:24 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jul 21 09:33:24 volumio volumio[958]: info: In handleBrowseUri, curUri=spotify
Jul 21 09:33:24 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:24 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:24 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:24 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:25 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jul 21 09:33:25 volumio volumio[958]: info: In handleBrowseUri, curUri=spotify/mytracks
Jul 21 09:33:26 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:26 volumio volumio[958]: info: Preloading song: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:4zM4eVNQOxDWLhQSLRgzQD in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:4VvvnRuao5g7iEWNtk37ay in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:63wEUQ8SN2S8nx2r21zTnl in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:4jecEDcnnoLbgdxfnpc76E in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:6Z9qTK7hFnHmITOFURnRix in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","service":"spop","name":"Wheel of Fortune","artist":"Allan Taylor","album":"Colour to the Moon","type":"song","duration":228,"albumart":"https://i.scdn.co/image/ab67616d0000b2732915ee9488e6e5b0af93c81e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4zM4eVNQOxDWLhQSLRgzQD","service":"spop","name":"A Road Too Long","artist":"Allan Taylor","album":"Colour to the Moon","type":"song","duration":248,"albumart":"https://i.scdn.co/image/ab67616d0000b2732915ee9488e6e5b0af93c81e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:6JsDrGMY0YkO3eQk9WWAdh in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:63wEUQ8SN2S8nx2r21zTnl","service":"spop","name":"Blues Boys Tune","artist":"B.B. King","album":"Blues On The Bayou","type":"song","duration":209,"albumart":"https://i.scdn.co/image/ab67616d0000b273cc8591492be4509025f80089","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:7pzVqCZdYKM7oEPwaiQchB in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4jecEDcnnoLbgdxfnpc76E","service":"spop","name":"Come With Me (From \"Godzilla\")","artist":"Big Movie Themes","album":"Come With Me (From \"Godzilla\")","type":"song","duration":363,"albumart":"https://i.scdn.co/image/ab67616d0000b273bec6ed173ae88162915614d2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:6hTcuIQa0sxrrByu9wTD7s in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6Z9qTK7hFnHmITOFURnRix","service":"spop","name":"Sweet Sixteen - Remastered 2001","artist":"Billy Idol","album":"Idolize Yourself: The Very Best Of Billy Idol","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2732121a2d5202ce105a6a8ef1e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:7DqTaelFf846rl1CHmyfOW in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6JsDrGMY0YkO3eQk9WWAdh","service":"spop","name":"Flesh For Fantasy - Remastered 1999","artist":"Billy Idol","album":"Idolize Yourself: The Very Best Of Billy Idol","type":"song","duration":278,"albumart":"https://i.scdn.co/image/ab67616d0000b2732121a2d5202ce105a6a8ef1e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:26 volumio volumio[958]: info: Exploding uri spotify:track:5ktgewipcGEOSSx0AHAvcQ in service spop
Jul 21 09:33:26 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4255lYm0MNtm4lr9XTE7VG in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7pzVqCZdYKM7oEPwaiQchB","service":"spop","name":"Eyes Without A Face - Remastered 1999","artist":"Billy Idol","album":"Idolize Yourself: The Very Best Of Billy Idol","type":"song","duration":298,"albumart":"https://i.scdn.co/image/ab67616d0000b2732121a2d5202ce105a6a8ef1e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6hTcuIQa0sxrrByu9wTD7s","service":"spop","name":"Born to Run","artist":"Bruce Springsteen","album":"Born To Run","type":"song","duration":269,"albumart":"https://i.scdn.co/image/ab67616d0000b273503143a281a3f30268dcd9f9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:3jnyp5HnsleyUENkfF2gjl in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7DqTaelFf846rl1CHmyfOW","service":"spop","name":"Chan Chan","artist":"Buena Vista Social Club","album":"Buena Vista Social Club","type":"song","duration":257,"albumart":"https://i.scdn.co/image/ab67616d0000b2731937a3b485ed7a71630809ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5KVak7r5YKcnkmARc0hy0Q in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ktgewipcGEOSSx0AHAvcQ","service":"spop","name":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b27384c8f71a38ebcd924d73de1e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4255lYm0MNtm4lr9XTE7VG","service":"spop","name":"Space Oddity - 2009 Remastered Version","artist":"David Bowie","album":"Nothing Has Changed (The Best Of David Bowie)","type":"song","duration":317,"albumart":"https://i.scdn.co/image/ab67616d0000b273e30ca7a6499c2aac5da0aaf2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4gvea7UlDkAvsJBPZAd4oB in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5pX3JnotIjrC6FIVY8v8Rn in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3jnyp5HnsleyUENkfF2gjl","service":"spop","name":"China Girl - Single Version; 2014 Remastered Version","artist":"David Bowie","album":"Nothing Has Changed (The Best Of David Bowie)","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b273e30ca7a6499c2aac5da0aaf2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0LLOnHO5FiT152vUuZIsLm in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5KVak7r5YKcnkmARc0hy0Q","service":"spop","name":"Private Investigations","artist":"Dire Straits","album":"Love Over Gold","type":"song","duration":405,"albumart":"https://i.scdn.co/image/ab67616d0000b273ec6de6665de5c6d43e4bf853","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4gvea7UlDkAvsJBPZAd4oB","service":"spop","name":"The Boys Of Summer","artist":"Don Henley","album":"Building The Perfect Beast","type":"song","duration":288,"albumart":"https://i.scdn.co/image/ab67616d0000b273e59d7ff5a9d7634c02135b19","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4svFYL3X54mWEmvOrEHrWa in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6BQNJ0JFKh8sWjQLI6Zudi in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:27 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::stPlaybackTimer
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::serviceStop
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::serviceStop
Jul 21 09:33:27 volumio volumio[958]: info: ControllerMpd::stop
Jul 21 09:33:27 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand stop
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:27 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:27 volumio volumio[958]: info: Using cached record of: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5pX3JnotIjrC6FIVY8v8Rn in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0LLOnHO5FiT152vUuZIsLm in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4svFYL3X54mWEmvOrEHrWa in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6BQNJ0JFKh8sWjQLI6Zudi in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:1EWyFFUCC3UgaliycAiKDR in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:185dxn5sEgOnBX5iwCDHkp in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:7nMl2aiwjNz4TIFoAkOrtG in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:3gGKOVwsAVvwt9BcH3k18J in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6vE90mi4yKsQGY3YD2OOv1 in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6TRZDhDxS4PJs3nxh9FBzk in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:3XLeGkYI3ekR5ByhrNauEN in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2N2yrmodOnVF10mKvItC9P in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2O0UWIMFeMtFR0LJMuIPjJ in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:45r7mbXRbpFAYZavAoX6tk in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2aoo2jlRnM3A0NyLQqMN2f in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:3QdefKbNfifFnCwlpLtQcG in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:1HEGcv63IZ7TPncpVKdVdN in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:32SkNdTcuxvUGjtv0ObOgu in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6F6DxQ3XjToEHX1e2KKSbg in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:22GbAGb80ZZNgm2yrBMnpR in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2nekCvC9XRXQckWNnkIp2l in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:23W5DHu31ZLW9q0p2wQxfN in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:176mKgRpX9i9v81eNcsxzf in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0xrkyEMkG4dVa5OMLQZOX8 in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5awDvzxWfd53SSrsRZ8pXO in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4Y8umLvMLWH3N3jAIPCXLV in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:7zto61V8ySp03Qi6X1LU2X in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4SCnjFSNQ56BmeamHqcOMA in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5HZBEcS9twpsb4ewrp3YXV in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6dGnYIeXmHdcikdzNNDMm2 in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0ZqSsO2xoVvcrhpiRuqCmt in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4olziiqxPRPnBE4H2mg6Xr in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2ngVqQ6LMnuHfBCMpn6TLt in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2PGCl9xqITb8tHYbz4ITSP in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0iGEKFEbrMTAHVBchC2ofn in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:64GCFR3C93W6aX7O5c4HzL in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:7hlB9kaYyOEcTpOKguHpC3 in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4j57JUOV0Sedy3umtfCdTZ in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:4jPaOGLcKx7qhYVJzP9j5Y in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:0NMayyyLgSWZ5xgahCtHaT in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:2a5pilG4Jh0lWElCj6Opm4 in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:5l547qhRU2DTC49o3UNZnf in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:27 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:27 volumio volumio[958]: info: Exploding uri spotify:track:6Gyk7ZHfFWo3d8U7poUEPs in service spop
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:27 volumio volumio[958]: info:
Jul 21 09:33:27 volumio volumio[958]: ---------------------------- MPD announces state update: player
Jul 21 09:33:27 volumio volumio[958]: info: sendMpdCommand stop took 254 milliseconds
Jul 21 09:33:27 volumio volumio[958]: info: ControllerMpd::getState
Jul 21 09:33:27 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand status
Jul 21 09:33:27 volumio volumio[958]: info: sendMpdCommand status took 38 milliseconds
Jul 21 09:33:27 volumio volumio[958]: verbose: ControllerMpd::parseState
Jul 21 09:33:27 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jul 21 09:33:27 volumio volumio[958]: info: sendMpdCommand playlistinfo took 19 milliseconds
Jul 21 09:33:27 volumio volumio[958]: verbose: ControllerMpd::parseTrackInfo
Jul 21 09:33:27 volumio volumio[958]: info: ControllerMpd::pushState
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::servicePushState
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Girl In The Yellow Dress","artist":"David Gilmour","album":"Rattle That Lock (Deluxe)","uri":"USB/7E19-E190/Music 1/David Gilmour/David_Gilmour_-_03_Faces_of_Stone (11).mp3","trackType":"mp3"}
Jul 21 09:33:27 volumio volumio[958]: verbose: CURRENT POSITION 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::syncState stateService stop
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::syncState currentStatus stop
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:27 volumio volumio[958]: info: No code
Jul 21 09:33:27 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:33:27 volumio volumio[958]: info: CorePlayQueue::getTrack 4
Jul 21 09:33:27 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:33:27 volumio volumio[958]: info: ------------------------------ 126ms
Jul 21 09:33:27 volumio volumio[958]: info: touch_display: Setting screensaver timeout to 120 seconds.
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:33:27 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0LLOnHO5FiT152vUuZIsLm","service":"spop","name":"Wooden Heart","artist":"Elvis Presley","album":"The 50 Greatest Hits","type":"song","duration":123,"albumart":"https://i.scdn.co/image/ab67616d0000b273b6cb10f041544fa1625f31f7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7zto61V8ySp03Qi6X1LU2X","service":"spop","name":"Tin Pan Alley (AKA Roughest Place in Town)","artist":"Stevie Ray Vaughan","album":"Couldn't Stand The Weather (Legacy Edition)","type":"song","duration":551,"albumart":"https://i.scdn.co/image/ab67616d0000b273eb72e98b6e645a68cdfe72a4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2O0UWIMFeMtFR0LJMuIPjJ","service":"spop","name":"Tennessee","artist":"Hans Zimmer","album":"Pearl Harbor - Original Motion Picture Soundtrack","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b273088f10626ed0592f4a4a9b72","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4olziiqxPRPnBE4H2mg6Xr","service":"spop","name":"Resurrected","artist":"The Dead Daisies","album":"Burn It Down","type":"song","duration":275,"albumart":"https://i.scdn.co/image/ab67616d0000b273f0f5f0ea133a3b4572c43cb0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4svFYL3X54mWEmvOrEHrWa","service":"spop","name":"River of Tears","artist":"Eric Clapton","album":"Clapton Chronicles: The Best of Eric Clapton","type":"song","duration":442,"albumart":"https://i.scdn.co/image/ab67616d0000b27384edd1376faafd5e350bd7a9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6dGnYIeXmHdcikdzNNDMm2","service":"spop","name":"Here Comes The Sun - Remastered 2009","artist":"The Beatles","album":"Abbey Road (Remastered)","type":"song","duration":185,"albumart":"https://i.scdn.co/image/ab67616d0000b273dc30583ba717007b00cceb25","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","service":"spop","name":"Face Your Fear","artist":"The Dead Daisies","album":"Radiance","type":"song","duration":249,"albumart":"https://i.scdn.co/image/ab67616d0000b273e5f836163a69f88bf85539be","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6Gyk7ZHfFWo3d8U7poUEPs","service":"spop","name":"Blue Jean Blues - 2005 Remaster","artist":"ZZ Top","album":"Fandango! (Expanded 2006 Remaster)","type":"song","duration":282,"albumart":"https://i.scdn.co/image/ab67616d0000b273b86736821a2d2f2da99b3963","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:22GbAGb80ZZNgm2yrBMnpR","service":"spop","name":"Wherever I May Roam","artist":"Metallica","album":"Metallica","type":"song","duration":403,"albumart":"https://i.scdn.co/image/ab67616d0000b273cf84c5b276431b473e924802","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2N2yrmodOnVF10mKvItC9P","service":"spop","name":"Don't Cry (Original)","artist":"Guns N' Roses","album":"Use Your Illusion I","type":"song","duration":283,"albumart":"https://i.scdn.co/image/ab67616d0000b273e44963b8bb127552ac761873","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1HEGcv63IZ7TPncpVKdVdN","service":"spop","name":"My One And Only Love","artist":"John Coltrane","album":"John Coltrane & Johnny Hartman","type":"song","duration":294,"albumart":"https://i.scdn.co/image/ab67616d0000b273fb071f5ed7df28378f67660f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2aoo2jlRnM3A0NyLQqMN2f","service":"spop","name":"All Along the Watchtower","artist":"Jimi Hendrix","album":"Electric Ladyland","type":"song","duration":240,"albumart":"https://i.scdn.co/image/ab67616d0000b273522088789d49e216d9818292","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0iGEKFEbrMTAHVBchC2ofn","service":"spop","name":"Far Away","artist":"The Dead Daisies","album":"Holy Ground","type":"song","duration":423,"albumart":"https://i.scdn.co/image/ab67616d0000b27308c43cccdb8a268adcb1d340","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2nekCvC9XRXQckWNnkIp2l","service":"spop","name":"Harvest Moon","artist":"Neil Young","album":"Eat, Pray, Love","type":"song","duration":299,"albumart":"https://i.scdn.co/image/ab67616d0000b273426288df0f8a68ea555c8d97","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6BQNJ0JFKh8sWjQLI6Zudi","service":"spop","name":"Change the World","artist":"Eric Clapton","album":"Clapton Chronicles: The Best of Eric Clapton","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed4b2a6ea7d8a04f39be0be0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4jPaOGLcKx7qhYVJzP9j5Y","service":"spop","name":"Radiance","artist":"The Dead Daisies","album":"Radiance","type":"song","duration":243,"albumart":"https://i.scdn.co/image/ab67616d0000b273e5f836163a69f88bf85539be","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5l547qhRU2DTC49o3UNZnf","service":"spop","name":"Out Of Time - Strings Version","artist":"The Rolling Stones","album":"Metamorphosis","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b273ce509c9fc49a17cbcc78c920","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:64GCFR3C93W6aX7O5c4HzL","service":"spop","name":"Long Way to Go","artist":"The Dead Daisies","album":"Make Some Noise","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b273d37ae3d743a1b14d545b05d4","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c","service":"spop","name":"The Lonely Shepherd","artist":"Gheorghe Zamfir","album":"Kill Bill Vol. 1 Original Soundtrack (PA Version)","type":"song","duration":260,"albumart":"https://i.scdn.co/image/ab67616d0000b273fecfac11994325a39cd03dec","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:23W5DHu31ZLW9q0p2wQxfN","service":"spop","name":"Time - 2011 Remastered Version","artist":"Pink Floyd","album":"The Dark Side Of The Moon (2011 Remastered Version)","type":"song","duration":413,"albumart":"https://i.scdn.co/image/ab67616d0000b273d29c2f17f8d5756a0e85ecde","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6F6DxQ3XjToEHX1e2KKSbg","service":"spop","name":"Simple Man","artist":"Lynyrd Skynyrd","album":"Pronounced 'Leh-'Nérd 'Skin-'Nérd (Expanded Edition)","type":"song","duration":357,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed9531fd3add18804cd6d7c1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4j57JUOV0Sedy3umtfCdTZ","service":"spop","name":"Kiss the Sun","artist":"The Dead Daisies","album":"Radiance","type":"song","duration":203,"albumart":"https://i.scdn.co/image/ab67616d0000b273e5f836163a69f88bf85539be","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4Y8umLvMLWH3N3jAIPCXLV","service":"spop","name":"Come with Me (Godzilla)","artist":"Spirital","album":"The Hunger - Horror Movie Themes","type":"song","duration":366,"albumart":"https://i.scdn.co/image/ab67616d0000b273eba4939aa16c8f3517a9eefa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3gGKOVwsAVvwt9BcH3k18J","service":"spop","name":"Three O'Clock Blues","artist":"Eric Clapton","album":"Riding with the King","type":"song","duration":516,"albumart":"https://i.scdn.co/image/ab67616d0000b273c11a2f41352af5dcb2a7e31a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5pX3JnotIjrC6FIVY8v8Rn","service":"spop","name":"Mary In the Morning","artist":"Elvis Presley","album":"From Elvis In Nashville","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2732379330cc9d3133cea047e41","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4svFYL3X54mWEmvOrEHrWa","service":"spop","name":"River of Tears","artist":"Eric Clapton","album":"Clapton Chronicles: The Best of Eric Clapton","type":"song","duration":442,"albumart":"https://i.scdn.co/image/ab67616d0000b27384edd1376faafd5e350bd7a9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0ZqSsO2xoVvcrhpiRuqCmt","service":"spop","name":"While My Guitar Gently Weeps - 2018 Mix","artist":"The Beatles","album":"The Beatles","type":"song","duration":285,"albumart":"https://i.scdn.co/image/ab67616d0000b2739daf50d073fd6e7ad9bc0076","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3XLeGkYI3ekR5ByhrNauEN","service":"spop","name":"Bangla Desh - Bonus Track","artist":"George Harrison","album":"Living In The Material World (Remastered)","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b2733c66fc5c22b3bfaa3c1ffd48","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5pX3JnotIjrC6FIVY8v8Rn","service":"spop","name":"Mary In the Morning","artist":"Elvis Presley","album":"From Elvis In Nashville","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2732379330cc9d3133cea047e41","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6BQNJ0JFKh8sWjQLI6Zudi","service":"spop","name":"Change the World","artist":"Eric Clapton","album":"Clapton Chronicles: The Best of Eric Clapton","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b273ed4b2a6ea7d8a04f39be0be0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6TRZDhDxS4PJs3nxh9FBzk","service":"spop","name":"Beware Of Darkness - Remastered 2014","artist":"George Harrison","album":"All Things Must Pass (Remastered 2014)","type":"song","duration":231,"albumart":"https://i.scdn.co/image/ab67616d0000b273acc11d868a59008935e72299","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5awDvzxWfd53SSrsRZ8pXO","service":"spop","name":"Du hast","artist":"Rammstein","album":"Sehnsucht","type":"song","duration":234,"albumart":"https://i.scdn.co/image/ab67616d0000b273a715d32590424cd667879ba3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2PGCl9xqITb8tHYbz4ITSP","service":"spop","name":"My Fate","artist":"The Dead Daisies","album":"Holy Ground","type":"song","duration":268,"albumart":"https://i.scdn.co/image/ab67616d0000b27308c43cccdb8a268adcb1d340","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:32SkNdTcuxvUGjtv0ObOgu","service":"spop","name":"Creep","artist":"Karen Souza","album":"Karen Souza Essentials","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b273172a64a71fd6910cea56af79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1EWyFFUCC3UgaliycAiKDR","service":"spop","name":"Old Love","artist":"Eric Clapton","album":"Journeyman","type":"song","duration":384,"albumart":"https://i.scdn.co/image/ab67616d0000b273f1e4230a291bd8d1c8e25ca1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6vE90mi4yKsQGY3YD2OOv1","service":"spop","name":"My Sweet Lord - 2014 Remaster","artist":"George Harrison","album":"All Things Must Pass (2014 Remaster)","type":"song","duration":281,"albumart":"https://i.scdn.co/image/ab67616d0000b2738a162cd60b075bef224ffab7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0NMayyyLgSWZ5xgahCtHaT","service":"spop","name":"Shine On","artist":"The Dead Daisies","album":"Radiance","type":"song","duration":180,"albumart":"https://i.scdn.co/image/ab67616d0000b273e5f836163a69f88bf85539be","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:176mKgRpX9i9v81eNcsxzf","service":"spop","name":"Rammstein","artist":"Rammstein","album":"Herzeleid","type":"song","duration":265,"albumart":"https://i.scdn.co/image/ab67616d0000b273c6e8760a62251a7f48eeead2","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0LLOnHO5FiT152vUuZIsLm","service":"spop","name":"Wooden Heart","artist":"Elvis Presley","album":"The 50 Greatest Hits","type":"song","duration":123,"albumart":"https://i.scdn.co/image/ab67616d0000b273b6cb10f041544fa1625f31f7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:45r7mbXRbpFAYZavAoX6tk","service":"spop","name":"Crockett's Theme - From \"Miami Vice II\" Soundtrack","artist":"Jan Hammer","album":"Escape From Television","type":"song","duration":214,"albumart":"https://i.scdn.co/image/ab67616d0000b273e943d965e240f8385a2e5ec3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5HZBEcS9twpsb4ewrp3YXV","service":"spop","name":"I Will Remember","artist":"TOTO","album":"Africa: The Best Of Toto","type":"song","duration":365,"albumart":"https://i.scdn.co/image/ab67616d0000b273562e01bfa76b6d312ccc56d6","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7hlB9kaYyOEcTpOKguHpC3","service":"spop","name":"Not Human","artist":"The Dead Daisies","album":"Radiance","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273e5f836163a69f88bf85539be","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2ngVqQ6LMnuHfBCMpn6TLt","service":"spop","name":"Judgement Day","artist":"The Dead Daisies","album":"Burn It Down","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273f0f5f0ea133a3b4572c43cb0","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7nMl2aiwjNz4TIFoAkOrtG","service":"spop","name":"Still Got The Blues","artist":"Eric Clapton","album":"Old Sock (Track By Track)","type":"song","duration":354,"albumart":"https://i.scdn.co/image/ab67616d0000b27362b9530584d27350a76183de","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3QdefKbNfifFnCwlpLtQcG","service":"spop","name":"Mountain Climbing","artist":"Joe Bonamassa","album":"Blues Of Desperation","type":"song","duration":343,"albumart":"https://i.scdn.co/image/ab67616d0000b2733ced540cb92570a29ffa0c1b","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:185dxn5sEgOnBX5iwCDHkp","service":"spop","name":"Bad Love","artist":"Eric Clapton","album":"Journeyman","type":"song","duration":308,"albumart":"https://i.scdn.co/image/ab67616d0000b273f1e4230a291bd8d1c8e25ca1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0xrkyEMkG4dVa5OMLQZOX8","service":"spop","name":"Engel","artist":"Rammstein","album":"Sehnsucht","type":"song","duration":264,"albumart":"https://i.scdn.co/image/ab67616d0000b273a715d32590424cd667879ba3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4SCnjFSNQ56BmeamHqcOMA","service":"spop","name":"Come With Me originally by Puff Daddy featuring Jimmy Page","artist":"Studio Group","album":"Pop Masters: Come With Me","type":"song","duration":364,"albumart":"https://i.scdn.co/image/ab67616d0000b273b4baff058328d6b8fe35946f","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Jul 21 09:33:28 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:28 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:28 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:28 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::play index 0
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:28 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:28 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:28 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:28 volumio volumio[958]: info: [1721547208520] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:28 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=debug msg="loading track spotify:track:4zM4eVNQOxDWLhQSLRgzQD (paused: false, position: 0ms)"
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:28 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4zM4eVNQOxDWLhQSLRgzQD","play_origin":"go-librespot"}}
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=debug msg="requested aes key for file 9b19559ca40d7ef61684859e08b2feda62cee197, gid: 4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:28 volumio go-librespot[1266]: time="2024-07-21T09:33:28+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:28 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:29 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:29 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:29 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:29 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:29 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:29 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:29 volumio volumio[958]: info: [1721547209050] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:29 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=debug msg="loading track spotify:track:4zM4eVNQOxDWLhQSLRgzQD (paused: false, position: 0ms)"
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:29 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4zM4eVNQOxDWLhQSLRgzQD","play_origin":"go-librespot"}}
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=debug msg="requested aes key for file 9b19559ca40d7ef61684859e08b2feda62cee197, gid: 4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:29 volumio go-librespot[1266]: time="2024-07-21T09:33:29+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:29 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:32 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:32 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:32 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:32 volumio volumio[958]: info: [1721547212413] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:32 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="loading track spotify:track:4zM4eVNQOxDWLhQSLRgzQD (paused: false, position: 0ms)"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:32 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4zM4eVNQOxDWLhQSLRgzQD","play_origin":"go-librespot"}}
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="requested aes key for file 9b19559ca40d7ef61684859e08b2feda62cee197, gid: 4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:32 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:32 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:32 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:32 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:32 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:32 volumio volumio[958]: info: [1721547212630] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:32 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="loading track spotify:track:4zM4eVNQOxDWLhQSLRgzQD (paused: false, position: 0ms)"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:32 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4zM4eVNQOxDWLhQSLRgzQD","play_origin":"go-librespot"}}
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=debug msg="requested aes key for file 9b19559ca40d7ef61684859e08b2feda62cee197, gid: 4zM4eVNQOxDWLhQSLRgzQD"
Jul 21 09:33:32 volumio go-librespot[1266]: time="2024-07-21T09:33:32+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:32 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:36 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:36 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::play index 1
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:36 volumio volumio[958]: info: [1721547216463] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:36 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:36 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:36 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:36 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:36 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:36 volumio volumio[958]: info: Using cached record of: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:36 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::play index 1
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:36 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:36 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:36 volumio volumio[958]: info: [1721547216664] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:36 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:36 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:36 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:36 volumio go-librespot[1266]: time="2024-07-21T09:33:36+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:36 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:37 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:37 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:37 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:37 volumio volumio[958]: info: [1721547217657] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:37 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:37 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:37 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:37 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:37 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:37 volumio volumio[958]: info: [1721547217809] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:37 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:37 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:37 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:37 volumio go-librespot[1266]: time="2024-07-21T09:33:37+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:38 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:38 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:38 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:38 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:38 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:38 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:38 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:38 volumio volumio[958]: info: Using cached record of: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:38 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:38 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::play index 1
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:38 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:38 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:38 volumio volumio[958]: info: [1721547218845] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:38 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:38 volumio go-librespot[1266]: time="2024-07-21T09:33:38+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:38 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:39 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:39 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:39 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:39 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:39 volumio volumio[958]: info: [1721547219679] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:39 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:39 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:39 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:39 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:39 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:39 volumio volumio[958]: info: CorePlayQueue::getTrack 1
Jul 21 09:33:39 volumio volumio[958]: info: [1721547219877] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:39 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:39 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:39 volumio go-librespot[1266]: time="2024-07-21T09:33:39+02:00" level=debug msg="loading track spotify:track:4VvvnRuao5g7iEWNtk37ay (paused: false, position: 0ms)"
Jul 21 09:33:40 volumio go-librespot[1266]: time="2024-07-21T09:33:40+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:40 volumio go-librespot[1266]: time="2024-07-21T09:33:40+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:40 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4VvvnRuao5g7iEWNtk37ay","play_origin":"go-librespot"}}
Jul 21 09:33:40 volumio go-librespot[1266]: time="2024-07-21T09:33:40+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:40 volumio go-librespot[1266]: time="2024-07-21T09:33:40+02:00" level=debug msg="requested aes key for file 5c74ef57cf67f41afd8f7dd057ef9d67ad5f6cc2, gid: 4VvvnRuao5g7iEWNtk37ay"
Jul 21 09:33:40 volumio go-librespot[1266]: time="2024-07-21T09:33:40+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:40 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:41 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:41 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:41 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:41 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:41 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:41 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:41 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:41 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:42 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:42 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4zM4eVNQOxDWLhQSLRgzQD
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4VvvnRuao5g7iEWNtk37ay
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:63wEUQ8SN2S8nx2r21zTnl
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6Z9qTK7hFnHmITOFURnRix
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6JsDrGMY0YkO3eQk9WWAdh
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:7pzVqCZdYKM7oEPwaiQchB
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6hTcuIQa0sxrrByu9wTD7s
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:7DqTaelFf846rl1CHmyfOW
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5ktgewipcGEOSSx0AHAvcQ
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4255lYm0MNtm4lr9XTE7VG
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:3jnyp5HnsleyUENkfF2gjl
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5KVak7r5YKcnkmARc0hy0Q
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4gvea7UlDkAvsJBPZAd4oB
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5pX3JnotIjrC6FIVY8v8Rn
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:0LLOnHO5FiT152vUuZIsLm
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4svFYL3X54mWEmvOrEHrWa
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6BQNJ0JFKh8sWjQLI6Zudi
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:1EWyFFUCC3UgaliycAiKDR
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:185dxn5sEgOnBX5iwCDHkp
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:7nMl2aiwjNz4TIFoAkOrtG
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:3gGKOVwsAVvwt9BcH3k18J
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6vE90mi4yKsQGY3YD2OOv1
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6TRZDhDxS4PJs3nxh9FBzk
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:3XLeGkYI3ekR5ByhrNauEN
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:3OQEVjVEQ6CvfAJ6XhTs6c
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2N2yrmodOnVF10mKvItC9P
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2O0UWIMFeMtFR0LJMuIPjJ
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:45r7mbXRbpFAYZavAoX6tk
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2aoo2jlRnM3A0NyLQqMN2f
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:3QdefKbNfifFnCwlpLtQcG
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:1HEGcv63IZ7TPncpVKdVdN
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:32SkNdTcuxvUGjtv0ObOgu
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6F6DxQ3XjToEHX1e2KKSbg
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:22GbAGb80ZZNgm2yrBMnpR
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2nekCvC9XRXQckWNnkIp2l
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:23W5DHu31ZLW9q0p2wQxfN
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:176mKgRpX9i9v81eNcsxzf
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:0xrkyEMkG4dVa5OMLQZOX8
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5awDvzxWfd53SSrsRZ8pXO
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4Y8umLvMLWH3N3jAIPCXLV
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:7zto61V8ySp03Qi6X1LU2X
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4SCnjFSNQ56BmeamHqcOMA
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5HZBEcS9twpsb4ewrp3YXV
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6dGnYIeXmHdcikdzNNDMm2
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:0ZqSsO2xoVvcrhpiRuqCmt
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4olziiqxPRPnBE4H2mg6Xr
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2ngVqQ6LMnuHfBCMpn6TLt
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2PGCl9xqITb8tHYbz4ITSP
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:0iGEKFEbrMTAHVBchC2ofn
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:64GCFR3C93W6aX7O5c4HzL
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:7hlB9kaYyOEcTpOKguHpC3
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4j57JUOV0Sedy3umtfCdTZ
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:4jPaOGLcKx7qhYVJzP9j5Y
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:0NMayyyLgSWZ5xgahCtHaT
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:5l547qhRU2DTC49o3UNZnf
Jul 21 09:33:42 volumio volumio[958]: info: Adding Item to queue: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:42 volumio volumio[958]: info: Using cached record of: spotify:track:6Gyk7ZHfFWo3d8U7poUEPs
Jul 21 09:33:42 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:42 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:42 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:42 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::play index 3
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:42 volumio volumio[958]: info: CorePlayQueue::getTrack 3
Jul 21 09:33:42 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:42 volumio volumio[958]: info: CorePlayQueue::getTrack 3
Jul 21 09:33:42 volumio volumio[958]: info: [1721547222035] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:42 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=debug msg="loading track spotify:track:4jecEDcnnoLbgdxfnpc76E (paused: false, position: 0ms)"
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:42 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4jecEDcnnoLbgdxfnpc76E","play_origin":"go-librespot"}}
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4jecEDcnnoLbgdxfnpc76E"
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=debug msg="requested aes key for file 27a8593e649958fdb8417c0162f868c512a409b6, gid: 4jecEDcnnoLbgdxfnpc76E"
Jul 21 09:33:42 volumio go-librespot[1266]: time="2024-07-21T09:33:42+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:42 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:33:46 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:46 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:46 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:33:46 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:33:46 volumio volumio[958]: info: Adding Item to queue: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:46 volumio volumio[958]: info: Using cached record of: spotify:track:4jecEDcnnoLbgdxfnpc76E
Jul 21 09:33:46 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:33:46 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::play index 0
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:46 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:33:46 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:33:46 volumio volumio[958]: info: [1721547226033] ControllerSpotify::clearAddPlayTrack
Jul 21 09:33:46 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=debug msg="loading track spotify:track:4jecEDcnnoLbgdxfnpc76E (paused: false, position: 0ms)"
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:33:46 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4jecEDcnnoLbgdxfnpc76E","play_origin":"go-librespot"}}
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:4jecEDcnnoLbgdxfnpc76E"
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=debug msg="requested aes key for file 27a8593e649958fdb8417c0162f868c512a409b6, gid: 4jecEDcnnoLbgdxfnpc76E"
Jul 21 09:33:46 volumio go-librespot[1266]: time="2024-07-21T09:33:46+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:33:46 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:00 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jul 21 09:34:00 volumio volumio[958]: info: In handleBrowseUri, curUri=spotify
Jul 21 09:34:00 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:00 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:00 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:00 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:10 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Jul 21 09:34:10 volumio volumio[958]: info: In handleBrowseUri, curUri=spotify/myrecentlyplayedtracks
Jul 21 09:34:10 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:11 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:11 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:34:11 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:34:11 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:11 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:34:11 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:34:11 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:34:11 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::play index 0
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:11 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:34:11 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:11 volumio volumio[958]: info: [1721547251569] ControllerSpotify::clearAddPlayTrack
Jul 21 09:34:11 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=debug msg="loading track spotify:track:2a5pilG4Jh0lWElCj6Opm4 (paused: false, position: 0ms)"
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:34:11 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","play_origin":"go-librespot"}}
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=debug msg="requested aes key for file 6686cf241a9e2e7ed3b8cb13aa9ad07a04658a91, gid: 2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:11 volumio go-librespot[1266]: time="2024-07-21T09:34:11+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:34:11 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:13 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:13 volumio volumio[958]: info: CoreCommandRouter::volumioReplaceandPlayItems
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::ClearQueue
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::clearPlayQueue
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:34:13 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::addQueueItems
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::addQueueItems
Jul 21 09:34:13 volumio volumio[958]: info: Preload queue cleared
Jul 21 09:34:13 volumio volumio[958]: info: Adding Item to queue: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:34:13 volumio volumio[958]: info: Using cached record of: spotify:track:2a5pilG4Jh0lWElCj6Opm4
Jul 21 09:34:13 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::saveQueue
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::getTrackBlock
Jul 21 09:34:13 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::play index 0
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::stop
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:13 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:34:13 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:13 volumio volumio[958]: info: [1721547253066] ControllerSpotify::clearAddPlayTrack
Jul 21 09:34:13 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=debug msg="loading track spotify:track:2a5pilG4Jh0lWElCj6Opm4 (paused: false, position: 0ms)"
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:34:13 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","play_origin":"go-librespot"}}
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=debug msg="requested aes key for file 6686cf241a9e2e7ed3b8cb13aa9ad07a04658a91, gid: 2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:13 volumio go-librespot[1266]: time="2024-07-21T09:34:13+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:34:13 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:22 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:34:22 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:34:22 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:22 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:22 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:34:22 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:22 volumio volumio[958]: info: [1721547262598] ControllerSpotify::clearAddPlayTrack
Jul 21 09:34:22 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=debug msg="loading track spotify:track:2a5pilG4Jh0lWElCj6Opm4 (paused: false, position: 0ms)"
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:34:22 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","play_origin":"go-librespot"}}
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=debug msg="requested aes key for file 6686cf241a9e2e7ed3b8cb13aa9ad07a04658a91, gid: 2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:22 volumio go-librespot[1266]: time="2024-07-21T09:34:22+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:34:22 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:23 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:23 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:34:23 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:23 volumio volumio[958]: info: [1721547263018] ControllerSpotify::clearAddPlayTrack
Jul 21 09:34:23 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="loading track spotify:track:2a5pilG4Jh0lWElCj6Opm4 (paused: false, position: 0ms)"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:34:23 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","play_origin":"go-librespot"}}
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="requested aes key for file 6686cf241a9e2e7ed3b8cb13aa9ad07a04658a91, gid: 2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:34:23 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:23 volumio volumio[958]: info: CoreCommandRouter::volumioPlay
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::play index undefined
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::setConsumeUpdateService undefined
Jul 21 09:34:23 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:23 volumio volumio[958]: info: CoreStateMachine::startPlaybackTimer
Jul 21 09:34:23 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:23 volumio volumio[958]: info: [1721547263272] ControllerSpotify::clearAddPlayTrack
Jul 21 09:34:23 volumio volumio[958]: info: Sending Spotify command with payload to local API: /player/play
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="loading track spotify:track:2a5pilG4Jh0lWElCj6Opm4 (paused: false, position: 0ms)"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=trace msg="emitting websocket event: will_play"
Jul 21 09:34:23 volumio volumio[958]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2a5pilG4Jh0lWElCj6Opm4","play_origin":"go-librespot"}}
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=debug msg="requested aes key for file 6686cf241a9e2e7ed3b8cb13aa9ad07a04658a91, gid: 2a5pilG4Jh0lWElCj6Opm4"
Jul 21 09:34:23 volumio go-librespot[1266]: time="2024-07-21T09:34:23+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed creating stream: failed retrieving audio key: failed retrieving aes key with code 1"
Jul 21 09:34:23 volumio volumio[958]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: info: Retrieving Cloud Streaming UI
Jul 21 09:34:28 volumio volumio[958]: info: Getting Tidal Cloud Configuration
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: info: Getting Qobuz Cloud Configuration
Jul 21 09:34:28 volumio volumio[958]: info: Asking plugin for UI Config
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: info: Getting Spotify Cloud Configuration
Jul 21 09:34:28 volumio volumio[958]: info: Asking plugin for UI Config
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: info: Saving Spotify Acccount
Jul 21 09:34:28 volumio volumio[958]: info: Got Tidal Cloud Configuration
Jul 21 09:34:28 volumio volumio[958]: info: Got it
Jul 21 09:34:28 volumio volumio[958]: info: Got it
Jul 21 09:34:28 volumio volumio[958]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::getUIConfigOnPlugin
Jul 21 09:34:28 volumio volumio[958]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::volumioGetBrowseSources
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::volumioGetBrowseSources
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::volumioGetBrowseSources
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Jul 21 09:34:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Jul 21 09:34:30 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand rescan
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand status
Jul 21 09:34:30 volumio volumio[958]: info:
Jul 21 09:34:30 volumio volumio[958]: ---------------------------- MPD announces state update: update
Jul 21 09:34:30 volumio volumio[958]: info: sendMpdCommand rescan took 9 milliseconds
Jul 21 09:34:30 volumio volumio[958]: info: ControllerMpd::getState
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand status
Jul 21 09:34:30 volumio volumio[958]: info: sendMpdCommand status took 5 milliseconds
Jul 21 09:34:30 volumio volumio[958]: info: sendMpdCommand status took 4 milliseconds
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::parseState
Jul 21 09:34:30 volumio volumio[958]: info: Command Router : Notfying DB Updatetrue
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::parseState
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Jul 21 09:34:30 volumio volumio[958]: info: sendMpdCommand playlistinfo took 12 milliseconds
Jul 21 09:34:30 volumio volumio[958]: verbose: ControllerMpd::parseTrackInfo
Jul 21 09:34:30 volumio volumio[958]: info: ControllerMpd::pushState
Jul 21 09:34:30 volumio volumio[958]: info: CoreCommandRouter::servicePushState
Jul 21 09:34:30 volumio volumio[958]: info: CoreStateMachine::pushState
Jul 21 09:34:30 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:30 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Jul 21 09:34:30 volumio volumio[958]: info: CoreCommandRouter::volumioPushState
Jul 21 09:34:30 volumio volumio[958]: info: CorePlayQueue::getTrack 0
Jul 21 09:34:30 volumio volumio[958]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd
Jul 21 09:34:30 volumio volumio[958]: info: ------------------------------ 118ms
Jul 21 09:34:30 volumio volumio[958]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29
Jul 21 09:34:30 volumio volumio[958]: SPOTIFY: SPOTIFY VOLUME 28
Jul 21 09:34:30 volumio volumio[958]: SPOTIFY: VOLUMIO VOLUME 29
Jul 21 09:34:30 volumio volumio[958]: SPOTIFY: DELTA VOLUME ENOUGH: false
Jul 21 09:34:32 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Jul 21 09:34:33 volumio volumio[958]: info: CoreCommandRouter::Close All Modals sent
Jul 21 09:34:36 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Jul 21 09:34:39 volumio volumio[958]: info: Disabling MyMusic plugin upnp
Jul 21 09:34:40 volumio sudo[2291]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service
Jul 21 09:34:40 volumio sudo[2291]: pam_unix(sudo:session): session opened for user root by (uid=0)
Jul 21 09:34:40 volumio volumio[958]: error: Upnp client error: Error: This socket has been ended by the other party
Jul 21 09:34:40 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD...
Jul 21 09:34:40 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Jul 21 09:34:43 volumio volumio[958]: info: Enabling MyMusic plugin upnp
Jul 21 09:34:43 volumio volumio[958]: info: Enabling plugin upnp
Jul 21 09:34:43 volumio volumio[958]: info: Loading plugin "upnp"...
Jul 21 09:34:43 volumio volumio[958]: info: [1721547283606] Starting Upmpd Daemon
Jul 21 09:34:43 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Jul 21 09:34:43 volumio volumio[958]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 21 09:34:43 volumio volumio[958]: Error: listen EADDRINUSE: address already in use :::6599
Jul 21 09:34:43 volumio volumio[958]: at Server.setupListenHandle [as _listen2] (net.js:1318:16)
Jul 21 09:34:43 volumio volumio[958]: at listenInCluster (net.js:1366:12)
Jul 21 09:34:43 volumio volumio[958]: at Server.listen (net.js:1452:7)
Jul 21 09:34:43 volumio volumio[958]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17)
Jul 21 09:34:43 volumio volumio[958]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38)
Jul 21 09:34:43 volumio volumio[958]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19)
Jul 21 09:34:43 volumio volumio[958]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Jul 21 09:34:43 volumio volumio[958]: at processTicksAndRejections (internal/process/task_queues.js:75:11) {
Jul 21 09:34:43 volumio volumio[958]: code: 'EADDRINUSE',
Jul 21 09:34:43 volumio volumio[958]: errno: -98,
Jul 21 09:34:43 volumio volumio[958]: syscall: 'listen',
Jul 21 09:34:43 volumio volumio[958]: address: '::',
Jul 21 09:34:43 volumio volumio[958]: port: 6599
Jul 21 09:34:43 volumio volumio[958]: }
Jul 21 09:34:43 volumio volumio[958]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Jul 21 09:34:44 volumio sudo[2311]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-21 09:33
Jul 21 09:34:44 volumio sudo[2311]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET"
VOLUMIO_VERSION="3.631"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"