-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sat 2024-10-19 12:58:51 CEST. --
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Boosie%20Badazz%20%26%20Tony%20Michael%20%5C%22Private%20Room%5C%22%20Feat.%20Rich%20Homie%20Quan%20(WSHH%20Exclusive)%22%2C%22artist%22%3A%22WORLDSTARHIPHOP%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FAzN7Zw4qafM%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCuoLnD06-soINE8kNZRCX1dUV8SQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22AzN7Zw4qafM%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A67%7D%7D%7D in service youtube2
Oct 19 12:57:00 volumio volumio[973]: info: [youtube2-browse] explodeUri: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Boosie%20Badazz%20%26%20Tony%20Michael%20%5C%22Private%20Room%5C%22%20Feat.%20Rich%20Homie%20Quan%20(WSHH%20Exclusive)%22%2C%22artist%22%3A%22WORLDSTARHIPHOP%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FAzN7Zw4qafM%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCuoLnD06-soINE8kNZRCX1dUV8SQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22AzN7Zw4qafM%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A67%7D%7D%7D
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22The%20Fugees%20-%20How%20Many%20Mics%22%2C%22artist%22%3A%22Fugees%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fki7gxLbhXkU%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAM6rQHlFOzYcYSSJrSf6PS8eY0pQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ki7gxLbhXkU%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A65%7D%7D%7D in service youtube2
Oct 19 12:57:00 volumio volumio[973]: info: [youtube2-browse] explodeUri: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22The%20Fugees%20-%20How%20Many%20Mics%22%2C%22artist%22%3A%22Fugees%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fki7gxLbhXkU%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAM6rQHlFOzYcYSSJrSf6PS8eY0pQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ki7gxLbhXkU%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A65%7D%7D%7D
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:47XeUH2soB35YXX6ktygWb in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:47XeUH2soB35YXX6ktygWb
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%2250%20Cent%2C%20Snoop%20Dogg%2C%20Nicki%20Minaj%20-%20Up%20In%20Smoke%20ft.%20Nate%20Dogg%2C%20Dr.%20Dre%2C%20Ice%20Cube%20(Music%20Video)%202023%22%2C%22artist%22%3A%22Spicy%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FcZU-TM1qTt4%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLD1TM4mf5PeLaJJu3bSBBaRtn4VdA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D%7D in service youtube2
Oct 19 12:57:00 volumio volumio[973]: info: [youtube2-browse] explodeUri: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%2250%20Cent%2C%20Snoop%20Dogg%2C%20Nicki%20Minaj%20-%20Up%20In%20Smoke%20ft.%20Nate%20Dogg%2C%20Dr.%20Dre%2C%20Ice%20Cube%20(Music%20Video)%202023%22%2C%22artist%22%3A%22Spicy%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FcZU-TM1qTt4%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLD1TM4mf5PeLaJJu3bSBBaRtn4VdA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D%7D
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:47XeUH2soB35YXX6ktygWb from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:6xiBw5s8JrFnEjrkz3jpUO in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:7lkb3da5sYqrxOM5hv8Tn1 in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7lkb3da5sYqrxOM5hv8Tn1
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:6xiBw5s8JrFnEjrkz3jpUO from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:0Bva51mvvibj22YOdNaKYf in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0Bva51mvvibj22YOdNaKYf
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:7lkb3da5sYqrxOM5hv8Tn1 from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:0YThXX1dqUpYBLyJNAsF9N in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0YThXX1dqUpYBLyJNAsF9N
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:0Bva51mvvibj22YOdNaKYf from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:6914nrqNob8EcW3qyEhihe in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6914nrqNob8EcW3qyEhihe
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:0YThXX1dqUpYBLyJNAsF9N from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:7sHHmnHfUXeVDcYN3GKt7h in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7sHHmnHfUXeVDcYN3GKt7h
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:6914nrqNob8EcW3qyEhihe from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Erykah%20Badu%20-%20Soldier%22%2C%22artist%22%3A%22Henri%20Royere%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FBsEVAYVX6Wc%2Fhqdefault.jpg%3Fsqp%3D-oaymwE2CNACELwBSFXyq4qpAygIARUAAIhCGAFwAcABBvABAfgBvgKAAtYBigIMCAAQARhHIFgoZTAP%26rs%3DAOn4CLBfDAlM1PdUYoQsRvyg8-w5uv_Zog%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22BsEVAYVX6Wc%22%2C%22playlistId%22%3A%22PLq4iq8uiRpXv-Iuvyd8Dtfsn0x1XTWTo2%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A4%7D%7D%7D in service youtube2
Oct 19 12:57:00 volumio volumio[973]: info: [youtube2-browse] explodeUri: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Erykah%20Badu%20-%20Soldier%22%2C%22artist%22%3A%22Henri%20Royere%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FBsEVAYVX6Wc%2Fhqdefault.jpg%3Fsqp%3D-oaymwE2CNACELwBSFXyq4qpAygIARUAAIhCGAFwAcABBvABAfgBvgKAAtYBigIMCAAQARhHIFgoZTAP%26rs%3DAOn4CLBfDAlM1PdUYoQsRvyg8-w5uv_Zog%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22BsEVAYVX6Wc%22%2C%22playlistId%22%3A%22PLq4iq8uiRpXv-Iuvyd8Dtfsn0x1XTWTo2%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A4%7D%7D%7D
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:7sHHmnHfUXeVDcYN3GKt7h from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:1s7oOCT8vauUh01PbJD6ps in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:1s7oOCT8vauUh01PbJD6ps
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:7LDq2cE0TQV66BXorbV8FD in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:1s7oOCT8vauUh01PbJD6ps from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:7LDq2cE0TQV66BXorbV8FD in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:7LDq2cE0TQV66BXorbV8FD from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:0WtM2NBVQNNJLh6scP13H8 in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:7LDq2cE0TQV66BXorbV8FD from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/volumio/app/plugins/miscellanea/albumart/icons/fa-tags.svg'
Oct 19 12:57:00 volumio volumio[973]: info: Exploding uri spotify:track:6nax0cWHj6TkiapwcGCZ2O in service spop
Oct 19 12:57:00 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6nax0cWHj6TkiapwcGCZ2O
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:0WtM2NBVQNNJLh6scP13H8 from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: error: Commandrouter: Cannot explode uri spotify:track:6nax0cWHj6TkiapwcGCZ2O from service spop: Error: Spotify API method getTrack failed: WebapiRegularError: An error occurred while communicating with Spotify's Web API.
Oct 19 12:57:00 volumio volumio[973]: Details: No token provided.
Oct 19 12:57:00 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Oct 19 12:57:02 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:02 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:03 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Oct 19 12:57:03 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Oct 19 12:57:05 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Oct 19 12:57:09 volumio volumio[973]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Oct 19 12:57:09 volumio volumio[973]: info: Received Get System Version
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 19 12:57:09 volumio volumio[973]: info: Received Get System Info
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Oct 19 12:57:09 volumio volumio[973]: info: Discovery: Getting this device information
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:09 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Oct 19 12:57:12 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:12 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:12 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:12 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:14 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Oct 19 12:57:14 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Oct 19 12:57:17 volumio go-librespot[1225]: time="2024-10-19T12:57:17+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF"
Oct 19 12:57:17 volumio volumio[973]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify
Oct 19 12:57:17 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:57:17 volumio volumio[973]: Cannot find translation for source Jellyfin
Oct 19 12:57:17 volumio volumio[973]: Cannot find translation for source YouTube2
Oct 19 12:57:17 volumio sudo[18030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service
Oct 19 12:57:17 volumio sudo[18030]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 19 12:57:17 volumio volumio[973]: info: Disabling plugin spop
Oct 19 12:57:17 volumio volumio[973]: info: Done.
Oct 19 12:57:17 volumio volumio[973]: info: Connection to go-librespot Websocket closed
Oct 19 12:57:17 volumio systemd[1]: Stopping go-librespot Daemon...
Oct 19 12:57:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM
Oct 19 12:57:17 volumio systemd[1]: go-librespot-daemon.service: Succeeded.
Oct 19 12:57:17 volumio systemd[1]: Stopped go-librespot Daemon.
Oct 19 12:57:17 volumio sudo[18030]: pam_unix(sudo:session): session closed for user root
Oct 19 12:57:17 volumio volumio[973]: ------------------------------------ BT MESSAGE: BT STATUS: running
Oct 19 12:57:20 volumio volumio[973]: info: Enabling plugin spop
Oct 19 12:57:20 volumio volumio[973]: info: Loading plugin "spop"...
Oct 19 12:57:20 volumio volumio[973]: info: PLUGIN START: spop
Oct 19 12:57:20 volumio volumio[973]: info: Creating Spotify config file
Oct 19 12:57:20 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Oct 19 12:57:20 volumio volumio[973]: info: Done.
Oct 19 12:57:20 volumio volumio[973]: info: Spotify config file written
Oct 19 12:57:20 volumio sudo[18034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Oct 19 12:57:20 volumio sudo[18034]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 19 12:57:20 volumio systemd[1]: Started go-librespot Daemon.
Oct 19 12:57:20 volumio go-librespot[18036]: Librespot-go daemon starting...
Oct 19 12:57:20 volumio sudo[18034]: pam_unix(sudo:session): session closed for user root
Oct 19 12:57:20 volumio go-librespot[18036]: time="2024-10-19T12:57:20+02:00" level=info msg="generated new device id: e7937d1cb234b7a4ab046d8b1451b70c5b642c8f"
Oct 19 12:57:20 volumio go-librespot[18036]: time="2024-10-19T12:57:20+02:00" level=debug msg="stored credentials found for 21iwmbfpqm7cn53tbmsjqqwbq"
Oct 19 12:57:20 volumio volumio[973]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Oct 19 12:57:20 volumio volumio[973]: SPOTIFY: BQASPGWGDB8K03SwrsUldl8B3EBzUoiHk1-hjscPQLrh6nIHIjAbvKvFFGEIlWgulvKBe9LFL2lE3y0eTB0bPWN5PeQIxOjsJcR_1GcxCJj7wdRDgSKkNjNbsoPqnTMN5h6oDwLpNBxqoEGkBqP5aYvuEvAfibfnppAeCWeTBhwGK1obd3KXHBtRV4YmoO8yFmZI3iivyOZt1r643jQBqr0gNlCtVKucgw2bGyCy3eULgNJex7qY0jm16iKljPJBlHQSEeFbC-oJ0FA
Oct 19 12:57:20 volumio volumio[973]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Oct 19 12:57:20 volumio volumio[973]: info: New Spotify access token = BQASPGWGDB8K03SwrsUldl8B3EBzUoiHk1-hjscPQLrh6nIHIjAbvKvFFGEIlWgulvKBe9LFL2lE3y0eTB0bPWN5PeQIxOjsJcR_1GcxCJj7wdRDgSKkNjNbsoPqnTMN5h6oDwLpNBxqoEGkBqP5aYvuEvAfibfnppAeCWeTBhwGK1obd3KXHBtRV4YmoO8yFmZI3iivyOZt1r643jQBqr0gNlCtVKucgw2bGyCy3eULgNJex7qY0jm16iKljPJBlHQSEeFbC-oJ0FA
Oct 19 12:57:20 volumio volumio[973]: info: Spotify credentials grant success - running version from March 24, 2019
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="zeroconf server listening on port 34045"
Oct 19 12:57:21 volumio volumio[973]: SPOTIFY: User informations: {"country":"FR","display_name":"Gary Soopin","email":"soopin@me.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/21iwmbfpqm7cn53tbmsjqqwbq"},"followers":{"href":null,"total":18},"href":"https://api.spotify.com/v1/users/21iwmbfpqm7cn53tbmsjqqwbq","id":"21iwmbfpqm7cn53tbmsjqqwbq","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=465948760205245&height=300&width=300&ext=1731892352&hash=Abb9QE80MrJPuy_4JtB_MHEV","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=465948760205245&height=50&width=50&ext=1731892352&hash=AbbWDP-Zpa_5N-DBHSPA2rM5","width":64}],"product":"premium","type":"user","uri":"spotify:user:21iwmbfpqm7cn53tbmsjqqwbq"}
Oct 19 12:57:21 volumio volumio[973]: info: Spotify Successfully logged in
Oct 19 12:57:21 volumio volumio[973]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Oct 19 12:57:21 volumio volumio[973]: info: [1729335441074] CoreMusicLibrary::Adding element Spotify
Oct 19 12:57:21 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:57:21 volumio volumio[973]: Cannot find translation for source Jellyfin
Oct 19 12:57:21 volumio volumio[973]: Cannot find translation for source YouTube2
Oct 19 12:57:21 volumio volumio[973]: Cannot find translation for source Spotify
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="obtained new client token: AAALdUxNVoxGhFflG8w7zd9wH6qPZ9rI96gKDylXPTETYdjDdr/N1L1viI6S5EfL/6kOpJXSdS2siZoho5+C1u1eaxRgTY8Rpy4Q5Rw4jN5YbLx8HwTc9HBR7SrBMk4r/IyKx0iMJWDgdEMVqugZ238KLZfsy6cF1iF3p34ZeJTRVJpLitd6F+jAE/ixmhXHUSXUYahF9Mdw/yNWCSbTdmtd8Q7w3qCHHyaSjtN3ruWkX31nMyeo6oo="
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="completed keyexchange"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="completed challenge"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="authenticated as 21iwmbfpqm7cn53tbmsjqqwbq"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="authenticated as 21iwmbfpqm7cn53tbmsjqqwbq"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="dealer connection opened"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="initializing zeroconf session, username: 21iwmbfpqm7cn53tbmsjqqwbq"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 495"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="autoplay enabled: false"
Oct 19 12:57:21 volumio go-librespot[18036]: time="2024-10-19T12:57:21+02:00" level=debug msg="received connection id: OGZhNzY1YjQtZmVjYy00YTI0LTg5MDEtZjgwOTRiNThkYjVkK2RlYWxlcit0Y3A6Ly8wYWNhNDEyOC5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArODBGOUM5MzdBMzJFNDUyRjRBRDlCNEJDQjgxM0E3NUMwOUYwOTVBOEJEOEZDMjZFRDc0NkNBMDlFNzE5NTE4MA=="
Oct 19 12:57:22 volumio go-librespot[18036]: time="2024-10-19T12:57:22+02:00" level=debug msg="put connect state because NEW_DEVICE"
Oct 19 12:57:22 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:22 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:23 volumio volumio[973]: info: go-librespot daemon successfully initialized
Oct 19 12:57:23 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:57:23 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:57:23 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:23 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:26 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:50vL0GaSAIXXWqUuzbR0xR
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0MGlHpo9P4HN4AsgG44GG7
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:52JaFaqmiyQ34vhQWfpb88
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:5kHSMRbZKyGwaSwNSRrQXV
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:2RcanAJpudPNDkyIe9DzKS
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:5aIVCx5tnk0ntmdiinnYvw
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:22nqbe5PCW7Fw5eHtGa3m7
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:1ERLTEddhtvU39NlYvleXM
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:47XeUH2soB35YXX6ktygWb
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:7lkb3da5sYqrxOM5hv8Tn1
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0Bva51mvvibj22YOdNaKYf
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0YThXX1dqUpYBLyJNAsF9N
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:6914nrqNob8EcW3qyEhihe
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:7sHHmnHfUXeVDcYN3GKt7h
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:1s7oOCT8vauUh01PbJD6ps
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:26 volumio volumio[973]: info: Preloading song: spotify:track:6nax0cWHj6TkiapwcGCZ2O
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:50vL0GaSAIXXWqUuzbR0xR in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:50vL0GaSAIXXWqUuzbR0xR
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:0MGlHpo9P4HN4AsgG44GG7 in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0MGlHpo9P4HN4AsgG44GG7
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:52JaFaqmiyQ34vhQWfpb88 in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:52JaFaqmiyQ34vhQWfpb88
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX","service":"spop","name":"Doin' Time","artist":"Lana Del Rey","album":"Norman Fucking Rockwell!","type":"song","duration":202,"albumart":"https://i.scdn.co/image/ab67616d0000b273879e9318cb9f4e05ee552ac9","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:50vL0GaSAIXXWqUuzbR0xR","service":"spop","name":"BONNTO","artist":"Avi S","album":"BONNTO","type":"song","duration":224,"albumart":"https://i.scdn.co/image/ab67616d0000b2732c1099cf77fea91e72fd51b7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:5kHSMRbZKyGwaSwNSRrQXV in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:5kHSMRbZKyGwaSwNSRrQXV
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0MGlHpo9P4HN4AsgG44GG7","service":"spop","name":"Electric (feat. Khalid)","artist":"Alina Baraz","album":"Electric (feat. Khalid)","type":"song","duration":245,"albumart":"https://i.scdn.co/image/ab67616d0000b27393840c45116c4f81d49a5791","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:2RcanAJpudPNDkyIe9DzKS in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:2RcanAJpudPNDkyIe9DzKS
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:52JaFaqmiyQ34vhQWfpb88","service":"spop","name":"Kayo","artist":"Avi S","album":"Kayo","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b2732a76beb1699b63c7fa2a28af","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:5aIVCx5tnk0ntmdiinnYvw in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:5aIVCx5tnk0ntmdiinnYvw
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5kHSMRbZKyGwaSwNSRrQXV","service":"spop","name":"Patha Patha Gugu - Drill Remix","artist":"Trinix Remix","album":"Patha Patha Gugu (Drill Remix)","type":"song","duration":127,"albumart":"https://i.scdn.co/image/ab67616d0000b2739178f3d1fece438f9b7f3521","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:0wZbmya59qgLpJqKJGTHnW in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2RcanAJpudPNDkyIe9DzKS","service":"spop","name":"Really Love","artist":"D'Angelo","album":"Black Messiah","type":"song","duration":344,"albumart":"https://i.scdn.co/image/ab67616d0000b2735fb07fa92d5d658edadf053a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:22nqbe5PCW7Fw5eHtGa3m7 in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:22nqbe5PCW7Fw5eHtGa3m7
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5aIVCx5tnk0ntmdiinnYvw","service":"spop","name":"Water","artist":"Tyla","album":"Water","type":"song","duration":200,"albumart":"https://i.scdn.co/image/ab67616d0000b273d20231861e86a6f74ef2393e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:0wZbmya59qgLpJqKJGTHnW in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0wZbmya59qgLpJqKJGTHnW","service":"spop","name":"Mo Solo","artist":"Blakkayo","album":"Soz Serye","type":"song","duration":271,"albumart":"https://i.scdn.co/image/ab67616d0000b27360264347a5e5a64eed66cf6e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:1ERLTEddhtvU39NlYvleXM in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:1ERLTEddhtvU39NlYvleXM
Oct 19 12:57:26 volumio volumio[973]: info: Initializing connection to go-librespot Websocket
Oct 19 12:57:26 volumio go-librespot[18036]: time="2024-10-19T12:57:26+02:00" level=debug msg="new websocket client"
Oct 19 12:57:26 volumio volumio[973]: info: Connection to go-librespot Websocket established
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:47XeUH2soB35YXX6ktygWb in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:47XeUH2soB35YXX6ktygWb
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:22nqbe5PCW7Fw5eHtGa3m7","service":"spop","name":"I Lied","artist":"Nicki Minaj","album":"The Pinkprint - Deluxe Edition","type":"song","duration":304,"albumart":"https://i.scdn.co/image/ab67616d0000b2735475c4e03dcc235b447a0dfa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0wZbmya59qgLpJqKJGTHnW","service":"spop","name":"Mo Solo","artist":"Blakkayo","album":"Soz Serye","type":"song","duration":271,"albumart":"https://i.scdn.co/image/ab67616d0000b27360264347a5e5a64eed66cf6e","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:26 volumio volumio[973]: info: Exploding uri spotify:track:6xiBw5s8JrFnEjrkz3jpUO in service spop
Oct 19 12:57:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1ERLTEddhtvU39NlYvleXM","service":"spop","name":"Smithereens","artist":"Rasharn Powell","album":"Dusk & Dawn","type":"song","duration":162,"albumart":"https://i.scdn.co/image/ab67616d0000b27345d8f40e62326557a1510486","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:7lkb3da5sYqrxOM5hv8Tn1 in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7lkb3da5sYqrxOM5hv8Tn1
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:47XeUH2soB35YXX6ktygWb","service":"spop","name":"Irie","artist":"Katchafire","album":"Best So Far","type":"song","duration":308,"albumart":"https://i.scdn.co/image/ab67616d0000b2735192c00679757765154da009","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:0Bva51mvvibj22YOdNaKYf in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0Bva51mvvibj22YOdNaKYf
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6xiBw5s8JrFnEjrkz3jpUO","service":"spop","name":"Blame Me","artist":"Feder","album":"Blame Me","type":"song","duration":198,"albumart":"https://i.scdn.co/image/ab67616d0000b273568b5fd43acfacf0e301d879","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:0YThXX1dqUpYBLyJNAsF9N in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0YThXX1dqUpYBLyJNAsF9N
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7lkb3da5sYqrxOM5hv8Tn1","service":"spop","name":"Tell Her","artist":"Sons of Zion","album":"Tell Her","type":"song","duration":233,"albumart":"https://i.scdn.co/image/ab67616d0000b2730797c4491f5ce6256f5fb194","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:6914nrqNob8EcW3qyEhihe in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6914nrqNob8EcW3qyEhihe
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0Bva51mvvibj22YOdNaKYf","service":"spop","name":"Shiverman","artist":"Fat Freddy's Drop","album":"Dr. Boondigga & The Big BW","type":"song","duration":634,"albumart":"https://i.scdn.co/image/ab67616d0000b2731605765a8f2351349c7aabe5","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:7sHHmnHfUXeVDcYN3GKt7h in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7sHHmnHfUXeVDcYN3GKt7h
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0YThXX1dqUpYBLyJNAsF9N","service":"spop","name":"If We Being Rëal","artist":"Yeat","album":"2093","type":"song","duration":172,"albumart":"https://i.scdn.co/image/ab67616d0000b2739567b80f50a5b9f0178ae993","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:1s7oOCT8vauUh01PbJD6ps in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:1s7oOCT8vauUh01PbJD6ps
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6914nrqNob8EcW3qyEhihe","service":"spop","name":"Yo Bunny","artist":"prodbycpkshawn","album":"Yo Bunny","type":"song","duration":110,"albumart":"https://i.scdn.co/image/ab67616d0000b2734e82199b608995626e527852","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:7LDq2cE0TQV66BXorbV8FD in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7sHHmnHfUXeVDcYN3GKt7h","service":"spop","name":"Floating (feat. Khalid)","artist":"Alina Baraz","album":"The Color Of You","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b2733b82d56eae69108ac6c72201","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:7LDq2cE0TQV66BXorbV8FD in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1s7oOCT8vauUh01PbJD6ps","service":"spop","name":"Calm Down (with Selena Gomez)","artist":"Rema","album":"Rave & Roses Ultra","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b273963265801aa5c9740ad159b7","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:0WtM2NBVQNNJLh6scP13H8 in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:27 volumio volumio[973]: info: Exploding uri spotify:track:6nax0cWHj6TkiapwcGCZ2O in service spop
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:6nax0cWHj6TkiapwcGCZ2O
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LDq2cE0TQV66BXorbV8FD","service":"spop","name":"Mwaka Moon","artist":"Kalash","album":"Mwaka Moon","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b273531966e5d3c515a15d4d9aba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7LDq2cE0TQV66BXorbV8FD","service":"spop","name":"Mwaka Moon","artist":"Kalash","album":"Mwaka Moon","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b273531966e5d3c515a15d4d9aba","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0WtM2NBVQNNJLh6scP13H8","service":"spop","name":"Calm Down (with Selena Gomez)","artist":"Rema","album":"Calm Down (with Selena Gomez)","type":"song","duration":239,"albumart":"https://i.scdn.co/image/ab67616d0000b273a3a7f38ea2033aa501afd4cf","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6nax0cWHj6TkiapwcGCZ2O","service":"spop","name":"Lost in My Boots","artist":"KWAYE","album":"Lost in My Boots","type":"song","duration":219,"albumart":"https://i.scdn.co/image/ab67616d0000b27372547187e856652d4943f243","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:57:28 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:28 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:57:28 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:57:28 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Fat%20Freddy's%20Drop%20-%20Midnight%20Marauders%20(Unofficial%20Video)%22%2C%22artist%22%3A%22AvonRuLeZ%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FREbDQ_53tIY%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLBUTJgsXfGPkncTgSXc-YX3FXQoTQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22REbDQ_53tIY%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A2%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Fat%20Freddy's%20Drop%20-%20Midnight%20Marauders%20(Unofficial%20Video)%22%2C%22artist%22%3A%22AvonRuLeZ%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FREbDQ_53tIY%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLBUTJgsXfGPkncTgSXc-YX3FXQoTQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22REbDQ_53tIY%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A2%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:50vL0GaSAIXXWqUuzbR0xR
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:50vL0GaSAIXXWqUuzbR0xR
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0Oqc0kKFsQ6MhFOLBNZIGX
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0MGlHpo9P4HN4AsgG44GG7
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0MGlHpo9P4HN4AsgG44GG7
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:52JaFaqmiyQ34vhQWfpb88
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:52JaFaqmiyQ34vhQWfpb88
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:5kHSMRbZKyGwaSwNSRrQXV
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:5kHSMRbZKyGwaSwNSRrQXV
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:2RcanAJpudPNDkyIe9DzKS
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:2RcanAJpudPNDkyIe9DzKS
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:5aIVCx5tnk0ntmdiinnYvw
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:5aIVCx5tnk0ntmdiinnYvw
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ZI9NoGW_TuE%22%2C%22playlistId%22%3A%22PLWa4R2I19VH7Mtxo3VvqwnNlXgLpf4_d3%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A183%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Victony%20-%20Many%20Man%20%7C%20A%20COLORS%20SHOW%22%2C%22artist%22%3A%22COLORS%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FZI9NoGW_TuE%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAbyCNO4upJoad3EIGtvRxjzV8flg%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ZI9NoGW_TuE%22%2C%22playlistId%22%3A%22PLWa4R2I19VH7Mtxo3VvqwnNlXgLpf4_d3%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A183%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ZI9NoGW_TuE%22%2C%22playlistId%22%3A%22PLWa4R2I19VH7Mtxo3VvqwnNlXgLpf4_d3%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A183%7D%7D@explodeTrackData:o=%7B%22title%22%3A%22Victony%20-%20Many%20Man%20%7C%20A%20COLORS%20SHOW%22%2C%22artist%22%3A%22COLORS%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FZI9NoGW_TuE%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAbyCNO4upJoad3EIGtvRxjzV8flg%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ZI9NoGW_TuE%22%2C%22playlistId%22%3A%22PLWa4R2I19VH7Mtxo3VvqwnNlXgLpf4_d3%22%2C%22params%22%3A%22OAE%253D%22%2C%22index%22%3A183%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:22nqbe5PCW7Fw5eHtGa3m7
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:22nqbe5PCW7Fw5eHtGa3m7
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0wZbmya59qgLpJqKJGTHnW
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:1ERLTEddhtvU39NlYvleXM
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:1ERLTEddhtvU39NlYvleXM
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: mnt/INTERNAL/DATA/Musique/Music/Fat Freddys Drop/Dr. Boondigga & The Big BW/02 Boondigga.m4a
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: mnt/INTERNAL/DATA/Musique/Music/Fat Freddys Drop/Dr. Boondigga & The Big BW/02 Boondigga.m4a
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22CAKE%20-%20Frank%20Sinatra%20(Official%20HD%20Video)%22%2C%22artist%22%3A%22CAKE%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F7xw49Y-bYYk%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCW8iJyDXM1I4svuqi79-XsuQycFQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%227xw49Y-bYYk%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A22%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22CAKE%20-%20Frank%20Sinatra%20(Official%20HD%20Video)%22%2C%22artist%22%3A%22CAKE%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2F7xw49Y-bYYk%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCW8iJyDXM1I4svuqi79-XsuQycFQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%227xw49Y-bYYk%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A22%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Boosie%20Badazz%20%26%20Tony%20Michael%20%5C%22Private%20Room%5C%22%20Feat.%20Rich%20Homie%20Quan%20(WSHH%20Exclusive)%22%2C%22artist%22%3A%22WORLDSTARHIPHOP%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FAzN7Zw4qafM%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCuoLnD06-soINE8kNZRCX1dUV8SQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22AzN7Zw4qafM%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A67%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Boosie%20Badazz%20%26%20Tony%20Michael%20%5C%22Private%20Room%5C%22%20Feat.%20Rich%20Homie%20Quan%20(WSHH%20Exclusive)%22%2C%22artist%22%3A%22WORLDSTARHIPHOP%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FAzN7Zw4qafM%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLCuoLnD06-soINE8kNZRCX1dUV8SQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22AzN7Zw4qafM%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A67%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22The%20Fugees%20-%20How%20Many%20Mics%22%2C%22artist%22%3A%22Fugees%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fki7gxLbhXkU%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAM6rQHlFOzYcYSSJrSf6PS8eY0pQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ki7gxLbhXkU%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A65%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22The%20Fugees%20-%20How%20Many%20Mics%22%2C%22artist%22%3A%22Fugees%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2Fki7gxLbhXkU%2Fhqdefault.jpg%3Fsqp%3D-oaymwEcCNACELwBSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLAM6rQHlFOzYcYSSJrSf6PS8eY0pQ%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22ki7gxLbhXkU%22%2C%22playlistId%22%3A%22LL%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A65%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:47XeUH2soB35YXX6ktygWb
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:47XeUH2soB35YXX6ktygWb
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%2250%20Cent%2C%20Snoop%20Dogg%2C%20Nicki%20Minaj%20-%20Up%20In%20Smoke%20ft.%20Nate%20Dogg%2C%20Dr.%20Dre%2C%20Ice%20Cube%20(Music%20Video)%202023%22%2C%22artist%22%3A%22Spicy%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FcZU-TM1qTt4%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLD1TM4mf5PeLaJJu3bSBBaRtn4VdA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@endpoint:o=%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D@explodeTrackData:o=%7B%22title%22%3A%2250%20Cent%2C%20Snoop%20Dogg%2C%20Nicki%20Minaj%20-%20Up%20In%20Smoke%20ft.%20Nate%20Dogg%2C%20Dr.%20Dre%2C%20Ice%20Cube%20(Music%20Video)%202023%22%2C%22artist%22%3A%22Spicy%20Music%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FcZU-TM1qTt4%2Fhq720.jpg%3Fsqp%3D-oaymwEcCNAFEJQDSFXyq4qpAw4IARUAAIhCGAFwAcABBg%3D%3D%26rs%3DAOn4CLD1TM4mf5PeLaJJu3bSBBaRtn4VdA%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22cZU-TM1qTt4%22%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:7lkb3da5sYqrxOM5hv8Tn1
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:7lkb3da5sYqrxOM5hv8Tn1
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0Bva51mvvibj22YOdNaKYf
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0Bva51mvvibj22YOdNaKYf
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0YThXX1dqUpYBLyJNAsF9N
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0YThXX1dqUpYBLyJNAsF9N
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:6914nrqNob8EcW3qyEhihe
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:6914nrqNob8EcW3qyEhihe
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:7sHHmnHfUXeVDcYN3GKt7h
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:7sHHmnHfUXeVDcYN3GKt7h
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Erykah%20Badu%20-%20Soldier%22%2C%22artist%22%3A%22Henri%20Royere%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FBsEVAYVX6Wc%2Fhqdefault.jpg%3Fsqp%3D-oaymwE2CNACELwBSFXyq4qpAygIARUAAIhCGAFwAcABBvABAfgBvgKAAtYBigIMCAAQARhHIFgoZTAP%26rs%3DAOn4CLBfDAlM1PdUYoQsRvyg8-w5uv_Zog%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22BsEVAYVX6Wc%22%2C%22playlistId%22%3A%22PLq4iq8uiRpXv-Iuvyd8Dtfsn0x1XTWTo2%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A4%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: youtube2/video@explodeTrackData:o=%7B%22title%22%3A%22Erykah%20Badu%20-%20Soldier%22%2C%22artist%22%3A%22Henri%20Royere%22%2C%22albumart%22%3A%22https%3A%2F%2Fi.ytimg.com%2Fvi%2FBsEVAYVX6Wc%2Fhqdefault.jpg%3Fsqp%3D-oaymwE2CNACELwBSFXyq4qpAygIARUAAIhCGAFwAcABBvABAfgBvgKAAtYBigIMCAAQARhHIFgoZTAP%26rs%3DAOn4CLBfDAlM1PdUYoQsRvyg8-w5uv_Zog%22%2C%22endpoint%22%3A%7B%22type%22%3A%22watch%22%2C%22payload%22%3A%7B%22videoId%22%3A%22BsEVAYVX6Wc%22%2C%22playlistId%22%3A%22PLq4iq8uiRpXv-Iuvyd8Dtfsn0x1XTWTo2%22%2C%22params%22%3A%22OAI%253D%22%2C%22index%22%3A4%7D%7D%7D
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:1s7oOCT8vauUh01PbJD6ps
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:1s7oOCT8vauUh01PbJD6ps
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:7LDq2cE0TQV66BXorbV8FD
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:28 volumio volumio[973]: info: Adding Item to queue: spotify:track:6nax0cWHj6TkiapwcGCZ2O
Oct 19 12:57:28 volumio volumio[973]: info: Using cached record of: spotify:track:6nax0cWHj6TkiapwcGCZ2O
Oct 19 12:57:28 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:57:28 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::play index 1
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::getTrack 1
Oct 19 12:57:28 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:57:28 volumio volumio[973]: info: CorePlayQueue::getTrack 1
Oct 19 12:57:28 volumio volumio[973]: info: [1729335448316] ControllerSpotify::clearAddPlayTrack
Oct 19 12:57:28 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="resolved context of track" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1472"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:57:28 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:50vL0GaSAIXXWqUuzbR0xR","play_origin":"go-librespot"}}
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="selected format OGG_VORBIS_320 (ca3d87a7db93cda052707b9e2b08f3ef9bb2865d)" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:28 volumio go-librespot[18036]: time="2024-10-19T12:57:28+02:00" level=debug msg="requested aes key for file ca3d87a7db93cda052707b9e2b08f3ef9bb2865d, gid: 50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=debug msg="fetched first chunk of 19, total size is 9789144 bytes" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:50vL0GaSAIXXWqUuzbR0xR: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:57:29 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio go-librespot[18036]: time="2024-10-19T12:57:29+02:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:50vL0GaSAIXXWqUuzbR0xR"
Oct 19 12:57:29 volumio volumio[973]: info: Getting Spotify volume
Oct 19 12:57:29 volumio volumio[973]: info: Spotify volume: 100
Oct 19 12:57:29 volumio volumio[973]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Oct 19 12:57:29 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:29 volumio volumio[973]: info: CorePlayQueue::getTrack 1
Oct 19 12:57:29 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:57:29 volumio volumio[973]: SPOTIFY: SPOTIFY VOLUME 100
Oct 19 12:57:29 volumio volumio[973]: SPOTIFY: VOLUMIO VOLUME 5
Oct 19 12:57:29 volumio volumio[973]: SPOTIFY: DELTA VOLUME ENOUGH: true
Oct 19 12:57:29 volumio volumio[973]: info: Setting Spotify Volume from Volumio: 5
Oct 19 12:57:31 volumio volumio[973]: SPOTIFY: SETTING SPOTIFY VOLUME 5
Oct 19 12:57:31 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/volume
Oct 19 12:57:31 volumio go-librespot[18036]: time="2024-10-19T12:57:31+02:00" level=debug msg="update volume to 3276/65535"
Oct 19 12:57:31 volumio go-librespot[18036]: time="2024-10-19T12:57:31+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Oct 19 12:57:31 volumio go-librespot[18036]: time="2024-10-19T12:57:31+02:00" level=trace msg="emitting websocket event: volume"
Oct 19 12:57:31 volumio volumio[973]: SPOTIFY: received: {"type":"volume","data":{"value":5,"max":100}}
Oct 19 12:57:31 volumio volumio[973]: SPOTIFY: RECEIVED SPOTIFY VOLUME 5
Oct 19 12:57:32 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:32 volumio volumio[973]: info: CorePlayQueue::getTrack 1
Oct 19 12:57:32 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:32 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:34 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:57:34 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:34 volumio volumio[973]: info: Adding Item to queue: spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:34 volumio volumio[973]: info: Using cached record of: spotify:track:0WtM2NBVQNNJLh6scP13H8
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:34 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:57:34 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:57:34 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:57:34 volumio volumio[973]: info: [1729335454070] ControllerSpotify::clearAddPlayTrack
Oct 19 12:57:34 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="resolved context of track" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:57:34 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0WtM2NBVQNNJLh6scP13H8","play_origin":"go-librespot"}}
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="selected format OGG_VORBIS_320 (790766a3e869696275111663114ef3eaf0888c29)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="requested aes key for file 790766a3e869696275111663114ef3eaf0888c29, gid: 0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="fetched first chunk of 20, total size is 10104688 bytes" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=trace msg="seek to 1ms (diff: 1ms, samples: 44, bytes: 0)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:0WtM2NBVQNNJLh6scP13H8: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:57:34 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:34 volumio go-librespot[18036]: time="2024-10-19T12:57:34+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:57:38 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:57:38 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:57:38 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:38 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:57:38 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:38 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:57:38 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:57:38 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:57:38 volumio volumio[973]: info: [1729335458499] ControllerSpotify::clearAddPlayTrack
Oct 19 12:57:38 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="resolved context of track" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:57:38 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0WtM2NBVQNNJLh6scP13H8","play_origin":"go-librespot"}}
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="selected format OGG_VORBIS_320 (790766a3e869696275111663114ef3eaf0888c29)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="requested aes key for file 790766a3e869696275111663114ef3eaf0888c29, gid: 0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="fetched first chunk of 20, total size is 10104688 bytes" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:0WtM2NBVQNNJLh6scP13H8: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:57:38 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:38 volumio go-librespot[18036]: time="2024-10-19T12:57:38+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:0WtM2NBVQNNJLh6scP13H8"
Oct 19 12:57:42 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:42 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:47 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 19 12:57:47 volumio volumio[973]: info: In handleBrowseUri, curUri=spotify
Oct 19 12:57:47 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:47 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:47 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:47 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:48 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 19 12:57:48 volumio volumio[973]: info: In handleBrowseUri, curUri=spotify/playlists
Oct 19 12:57:49 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:57:52 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:57:52 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:57:52 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:52 volumio volumio[973]: info: Listing playlists
Oct 19 12:57:53 volumio nmbd[743]: [2024/10/19 12:57:53.102207, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response)
Oct 19 12:57:53 volumio nmbd[743]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.86.60 for name WORKGROUP<1d>.
Oct 19 12:57:53 volumio nmbd[743]: This response was from IP 192.168.86.47, reporting an IP address of 192.168.86.47.
Oct 19 12:58:02 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:58:02 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:03 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Oct 19 12:58:03 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Oct 19 12:58:03 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:04 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Oct 19 12:58:04 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:06 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:06 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:06 volumio volumio[973]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s17696&filter=s:popular
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:06 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:06 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:06 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:06 volumio volumio[973]: info: [1729335486591] ControllerWebradio::clearAddPlayTrack
Oct 19 12:58:06 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand stop
Oct 19 12:58:06 volumio volumio[973]: info: sendMpdCommand stop took 10 milliseconds
Oct 19 12:58:06 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clear
Oct 19 12:58:06 volumio volumio[973]: info:
Oct 19 12:58:06 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:06 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:06 volumio volumio[973]: info: sendMpdCommand clear took 3 milliseconds
Oct 19 12:58:06 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand load "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:06 volumio volumio[973]: info:
Oct 19 12:58:06 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:06 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:06 volumio volumio[973]: info:
Oct 19 12:58:06 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:06 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:06 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:06 volumio volumio[973]: info: ------------------------------ 8ms
Oct 19 12:58:07 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:07 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:07 volumio volumio[973]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s17696&filter=s:popular
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:07 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:07 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:07 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:07 volumio volumio[973]: info: [1729335487941] ControllerWebradio::clearAddPlayTrack
Oct 19 12:58:07 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand stop
Oct 19 12:58:08 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:08 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:08 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:08 volumio volumio[973]: info:
Oct 19 12:58:08 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:08 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:08 volumio volumio[973]: info: ------------------------------ 2318ms
Oct 19 12:58:08 volumio volumio[973]: info: ------------------------------ 2317ms
Oct 19 12:58:08 volumio volumio[973]: info: sendMpdCommand stop took 985 milliseconds
Oct 19 12:58:08 volumio volumio[973]: info: sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3" took 2 milliseconds
Oct 19 12:58:08 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clear
Oct 19 12:58:08 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 19 12:58:08 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand play
Oct 19 12:58:08 volumio volumio[973]: info:
Oct 19 12:58:08 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:08 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:08 volumio volumio[973]: info: ------------------------------ 3ms
Oct 19 12:58:08 volumio volumio[973]: info: sendMpdCommand clear took 2 milliseconds
Oct 19 12:58:08 volumio volumio[973]: info: sendMpdCommand play took 3 milliseconds
Oct 19 12:58:08 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand load "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:08 volumio volumio[973]: info:
Oct 19 12:58:08 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:08 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:08 volumio volumio[973]: info:
Oct 19 12:58:08 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:08 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:08 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:08 volumio volumio[973]: info: ------------------------------ 6ms
Oct 19 12:58:09 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:09 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:09 volumio volumio[973]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s17696&filter=s:popular
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:09 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:09 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:09 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:09 volumio volumio[973]: info: [1729335489090] ControllerWebradio::clearAddPlayTrack
Oct 19 12:58:09 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand stop
Oct 19 12:58:10 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:10 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 1596ms
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 1593ms
Oct 19 12:58:10 volumio volumio[973]: info: sendMpdCommand stop took 1437 milliseconds
Oct 19 12:58:10 volumio volumio[973]: info: sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3" took 2 milliseconds
Oct 19 12:58:10 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clear
Oct 19 12:58:10 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 19 12:58:10 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand play
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:10 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 5ms
Oct 19 12:58:10 volumio volumio[973]: info: sendMpdCommand clear took 4 milliseconds
Oct 19 12:58:10 volumio volumio[973]: info: sendMpdCommand play took 5 milliseconds
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 4ms
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 4ms
Oct 19 12:58:10 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand load "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: info:
Oct 19 12:58:10 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:10 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:10 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:10 volumio volumio[973]: info: ------------------------------ 5ms
Oct 19 12:58:12 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:12 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:12 volumio volumio[973]: info:
Oct 19 12:58:12 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:12 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:12 volumio volumio[973]: info: ------------------------------ 1588ms
Oct 19 12:58:12 volumio volumio[973]: info: ------------------------------ 1587ms
Oct 19 12:58:12 volumio volumio[973]: info: sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3" took 2 milliseconds
Oct 19 12:58:12 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 19 12:58:12 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand play
Oct 19 12:58:12 volumio volumio[973]: info:
Oct 19 12:58:12 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:12 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:12 volumio volumio[973]: info:
Oct 19 12:58:12 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:12 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:12 volumio volumio[973]: info: ------------------------------ 3ms
Oct 19 12:58:12 volumio volumio[973]: info: sendMpdCommand play took 2 milliseconds
Oct 19 12:58:12 volumio volumio[973]: info: ------------------------------ 2ms
Oct 19 12:58:12 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:58:12 volumio volumio[973]: info: Listing playlists
Oct 19 12:58:12 volumio volumio[973]: info: Listing playlists
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 12 milliseconds
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 12 milliseconds
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: info:
Oct 19 12:58:13 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 29 milliseconds
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 30 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand clearerror took 23 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand clearerror took 20 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 11 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 12 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 10 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand status took 9 milliseconds
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 114ms
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 109ms
Oct 19 12:58:13 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand clearerror took 121 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand clearerror took 119 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 110 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 109 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 108 milliseconds
Oct 19 12:58:13 volumio volumio[973]: info: sendMpdCommand playlistinfo took 107 milliseconds
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:13 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:13 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:13 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:13 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:13 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:13 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 230ms
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 229ms
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 210ms
Oct 19 12:58:13 volumio volumio[973]: info: ------------------------------ 209ms
Oct 19 12:58:13 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:13 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:13 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:13 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:21 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:21 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:21 volumio volumio[973]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s17696&filter=s:popular
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:21 volumio volumio[973]: info: [1729335501604] ControllerWebradio::clearAddPlayTrack
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand stop
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand stop took 7 milliseconds
Oct 19 12:58:21 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clear
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:21 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:21 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:21 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand status took 4 milliseconds
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand clear took 3 milliseconds
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand status took 2 milliseconds
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand status took 1 milliseconds
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand load "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:21 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:21 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:21 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
Oct 19 12:58:21 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:21 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:21 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:21 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:21 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:21 volumio volumio[973]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd
Oct 19 12:58:21 volumio volumio[973]: info: ------------------------------ 51ms
Oct 19 12:58:21 volumio volumio[973]: info: ------------------------------ 51ms
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:21 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:21 volumio volumio[973]: info:
Oct 19 12:58:21 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:21 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:21 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:21 volumio volumio[973]: info: ------------------------------ 55ms
Oct 19 12:58:21 volumio volumio[973]: info: sendMpdCommand playlistinfo took 53 milliseconds
Oct 19 12:58:21 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:21 volumio volumio[973]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined
Oct 19 12:58:21 volumio volumio[973]: info: ------------------------------ 60ms
Oct 19 12:58:21 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:21 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:22 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:58:22 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:23 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:23 volumio volumio[973]: error: updateQueue error: null
Oct 19 12:58:23 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3"
Oct 19 12:58:23 volumio volumio[973]: info: ------------------------------ 1641ms
Oct 19 12:58:23 volumio volumio[973]: info: ------------------------------ 1640ms
Oct 19 12:58:23 volumio volumio[973]: info:
Oct 19 12:58:23 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:23 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:23 volumio volumio[973]: info: sendMpdCommand add "https://novazz.ice.infomaniak.ch/novazz-128.mp3" took 1 milliseconds
Oct 19 12:58:23 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService mpd
Oct 19 12:58:23 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand play
Oct 19 12:58:23 volumio volumio[973]: info:
Oct 19 12:58:23 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:23 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:23 volumio volumio[973]: info:
Oct 19 12:58:23 volumio volumio[973]: ---------------------------- MPD announces system playlist update
Oct 19 12:58:23 volumio volumio[973]: info: Ignoring MPD Status Update
Oct 19 12:58:23 volumio volumio[973]: info: ------------------------------ 3ms
Oct 19 12:58:23 volumio volumio[973]: info: sendMpdCommand play took 3 milliseconds
Oct 19 12:58:23 volumio volumio[973]: info: ------------------------------ 2ms
Oct 19 12:58:23 volumio volumio[973]: info: ------------------------------ 1ms
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::volumioSeek
Oct 19 12:58:24 volumio volumio[973]: info: CoreStateMachine::seek
Oct 19 12:58:24 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:24 volumio volumio[973]: info: TRACKBLOCK {"service":"webradio","type":"track","uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","name":"Radio Nova","albumart":"http://cdn-profiles.tunein.com/s17696/images/logoq.png?t=163163","samplerate":"","bitdepth":"","channels":0,"trackType":"webradio"}
Oct 19 12:58:24 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:24 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:24 volumio volumio[973]: info: [1729335504463] ControllerWebradio::seek
Oct 19 12:58:24 volumio volumio[973]: info: ControllerMpd::seek
Oct 19 12:58:24 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:24 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:24 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:24 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:24 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 19 12:58:26 volumio volumio[973]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:005UX41NozyvvXRjqaHw0X
Oct 19 12:58:26 volumio volumio[973]: error: null
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 16 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 16 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 16 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 15 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand clearerror
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 13 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: info:
Oct 19 12:58:26 volumio volumio[973]: ---------------------------- MPD announces state update: player
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::getState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand status
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand clearerror took 42 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand clearerror took 41 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand clearerror took 41 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand clearerror took 40 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand clearerror took 39 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 14 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 13 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 13 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 13 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 13 milliseconds
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand status took 11 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseState
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ------------------------------ 181ms
Oct 19 12:58:26 volumio volumio[973]: info: ------------------------------ 180ms
Oct 19 12:58:26 volumio volumio[973]: info: ------------------------------ 178ms
Oct 19 12:58:26 volumio volumio[973]: info: sendMpdCommand playlistinfo took 122 milliseconds
Oct 19 12:58:26 volumio volumio[973]: verbose: ControllerMpd::parseTrackInfo
Oct 19 12:58:26 volumio volumio[973]: info: ControllerMpd::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::servicePushState
Oct 19 12:58:26 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:26 volumio volumio[973]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"novazz-128.mp3","artist":null,"album":null,"uri":"https://novazz.ice.infomaniak.ch/novazz-128.mp3","trackType":"mp3"}
Oct 19 12:58:26 volumio volumio[973]: verbose: CURRENT POSITION 0
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState stateService pause
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::syncState currentStatus stop
Oct 19 12:58:26 volumio volumio[973]: info: CoreStateMachine::pushState
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::volumioPushState
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output update for this device
Oct 19 12:58:26 volumio volumio[973]: info: MRS: Pushing multiroomSync output
Oct 19 12:58:26 volumio volumio[973]: info: ------------------------------ 164ms
Oct 19 12:58:26 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:26 volumio volumio[973]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.YMplItOe8zPnk3xm9VzBwtAJR8Q2.8eaa89ea280bf986011c91bdbb1138d3.state.status'
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: RECEIVED VOLUMIO VOLUME 5
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 19 12:58:26 volumio volumio[973]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:005UX41NozyvvXRjqaHw0X
Oct 19 12:58:26 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri
Oct 19 12:58:26 volumio volumio[973]: info: In handleBrowseUri, curUri=spotify:user:spotify:playlist:005UX41NozyvvXRjqaHw0X
Oct 19 12:58:26 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:26 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:26 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:26 volumio volumio[973]: info: Preloading song: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:26 volumio volumio[973]: info: Exploding uri spotify:track:0ydoqpTVhaDzjDg7WVcg4m in service spop
Oct 19 12:58:26 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:26 volumio volumio[973]: info: Exploding uri spotify:track:0WHGlVMA9L4EelsMEXgKiJ in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:79WNuukBSoDzaem1LT4IZ4 in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0ydoqpTVhaDzjDg7WVcg4m","service":"spop","name":"Drift","artist":"Teejay","album":"Drift","type":"song","duration":163,"albumart":"https://i.scdn.co/image/ab67616d0000b273aead5cd9b9fa8e19b09883f3","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:4UldILPVpnZO69ffK4B9aA in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:3Gs1GKlY3g9Z3ufw0suxZH in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0WHGlVMA9L4EelsMEXgKiJ","service":"spop","name":"Bleu Marine - A COLORS SHOW","artist":"Jewel Usain","album":"Bleu Marine - A COLORS SHOW","type":"song","duration":255,"albumart":"https://i.scdn.co/image/ab67616d0000b2736bf1128cae132865453fa516","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:2vLWF4yFhTHQZVwrPTjH1s in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:79WNuukBSoDzaem1LT4IZ4","service":"spop","name":"Vivant","artist":"Malik Djoudi","album":"Vivant","type":"song","duration":182,"albumart":"https://i.scdn.co/image/ab67616d0000b27332725683507151e552b15a62","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4UldILPVpnZO69ffK4B9aA","service":"spop","name":"Tubarão Te Amo","artist":"Dj LK da Escócia","album":"Tubarão Te Amo","type":"song","duration":149,"albumart":"https://i.scdn.co/image/ab67616d0000b2733a47cf79847798bd0118d916","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:1zi7xx7UVEFkmKfv06H8x0 in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:27 volumio volumio[973]: info: Exploding uri spotify:track:2c00DlvpzthGKcyXpe5GHa in service spop
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: EXPLODING URI:spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3Gs1GKlY3g9Z3ufw0suxZH","service":"spop","name":"Warm in These Blue Jeans","artist":"Rasharn Powell","album":"Dusk & Dawn","type":"song","duration":329,"albumart":"https://i.scdn.co/image/ab67616d0000b27345d8f40e62326557a1510486","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2vLWF4yFhTHQZVwrPTjH1s","service":"spop","name":"Floating (feat. Khalid)","artist":"Alina Baraz","album":"The Color Of You","type":"song","duration":174,"albumart":"https://i.scdn.co/image/ab67616d0000b2733c054a9aaef660a1fabf87aa","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1zi7xx7UVEFkmKfv06H8x0","service":"spop","name":"One Dance","artist":"Drake","album":"Views","type":"song","duration":173,"albumart":"https://i.scdn.co/image/ab67616d0000b2739416ed64daf84936d89e671c","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:27 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","service":"spop","name":"Bad Influence","artist":"Omah Lay","album":"Bad Influence","type":"song","duration":138,"albumart":"https://i.scdn.co/image/ab67616d0000b273c3ab09862088c3c9148b3e36","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:58:32 volumio volumio[973]: info: Listing playlists
Oct 19 12:58:32 volumio volumio[973]: info: Listing playlists
Oct 19 12:58:32 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:32 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:0ydoqpTVhaDzjDg7WVcg4m
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:6xiBw5s8JrFnEjrkz3jpUO
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:0WHGlVMA9L4EelsMEXgKiJ
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:79WNuukBSoDzaem1LT4IZ4
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:4UldILPVpnZO69ffK4B9aA
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:3Gs1GKlY3g9Z3ufw0suxZH
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:2vLWF4yFhTHQZVwrPTjH1s
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:1zi7xx7UVEFkmKfv06H8x0
Oct 19 12:58:32 volumio volumio[973]: info: Adding Item to queue: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:32 volumio volumio[973]: info: Using cached record of: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::play index 8
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::getTrack 8
Oct 19 12:58:32 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:32 volumio volumio[973]: info: CorePlayQueue::getTrack 8
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:32 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:32 volumio volumio[973]: info: [1729335512922] ControllerSpotify::clearAddPlayTrack
Oct 19 12:58:32 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:58:32 volumio go-librespot[18036]: time="2024-10-19T12:58:32+02:00" level=debug msg="resolved context of track" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:32 volumio go-librespot[18036]: time="2024-10-19T12:58:32+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:32 volumio go-librespot[18036]: time="2024-10-19T12:58:32+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:58:33 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","play_origin":"go-librespot"}}
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="selected format OGG_VORBIS_320 (3cfe40b98b58807ed9f551295e39e2337055371e)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="requested aes key for file 3cfe40b98b58807ed9f551295e39e2337055371e, gid: 2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="fetched first chunk of 11, total size is 5473352 bytes" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:2c00DlvpzthGKcyXpe5GHa: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:58:33 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:33 volumio go-librespot[18036]: time="2024-10-19T12:58:33+02:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:35 volumio volumio[973]: info: Adding spotify:track:2c00DlvpzthGKcyXpe5GHa to favourites using generic method
Oct 19 12:58:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: spop , getTrack
Oct 19 12:58:35 volumio volumio[973]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","service":"spop","name":"Bad Influence","artist":"Omah Lay","album":"Bad Influence","type":"song","duration":138,"albumart":"https://i.scdn.co/image/ab67616d0000b273c3ab09862088c3c9148b3e36","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}]
Oct 19 12:58:35 volumio volumio[973]: info: Saving Cloud item favourites
Oct 19 12:58:35 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_volumio , saveCloudItem
Oct 19 12:58:35 volumio volumio[973]: info: Pushing Favourites {"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","favourite":true}
Oct 19 12:58:37 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::volumioReplaceandPlayItems
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::ClearQueue
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::clearPlayQueue
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::addQueueItems
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::addQueueItems
Oct 19 12:58:37 volumio volumio[973]: info: Preload queue cleared
Oct 19 12:58:37 volumio volumio[973]: info: Adding Item to queue: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:37 volumio volumio[973]: info: Using cached record of: spotify:track:2c00DlvpzthGKcyXpe5GHa
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::volumioPushQueue
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::saveQueue
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::updateTrackBlock
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::getTrackBlock
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::play index 0
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::stop
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:37 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:37 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:37 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:37 volumio volumio[973]: info: [1729335517534] ControllerSpotify::clearAddPlayTrack
Oct 19 12:58:37 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="resolved context of track" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:58:37 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","play_origin":"go-librespot"}}
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="selected format OGG_VORBIS_320 (3cfe40b98b58807ed9f551295e39e2337055371e)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="requested aes key for file 3cfe40b98b58807ed9f551295e39e2337055371e, gid: 2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="fetched first chunk of 11, total size is 5473352 bytes" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:37 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:2c00DlvpzthGKcyXpe5GHa: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:58:37 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:58:37 volumio go-librespot[18036]: time="2024-10-19T12:58:37+02:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:38 volumio go-librespot[18036]: time="2024-10-19T12:58:38+02:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:38 volumio go-librespot[18036]: time="2024-10-19T12:58:38+02:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:42 volumio volumio[973]: info: CoreCommandRouter::volumioGetState
Oct 19 12:58:42 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:45 volumio volumio[973]: info: CoreCommandRouter::volumioPlay
Oct 19 12:58:45 volumio volumio[973]: info: CoreStateMachine::play index undefined
Oct 19 12:58:45 volumio volumio[973]: info: CoreStateMachine::setConsumeUpdateService undefined
Oct 19 12:58:45 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:45 volumio volumio[973]: info: CoreStateMachine::startPlaybackTimer
Oct 19 12:58:45 volumio volumio[973]: info: CorePlayQueue::getTrack 0
Oct 19 12:58:45 volumio volumio[973]: info: CoreCommandRouter::volumioGetVisibleSources
Oct 19 12:58:45 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Oct 19 12:58:45 volumio volumio[973]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Oct 19 12:58:45 volumio volumio[973]: info: [1729335525294] ControllerSpotify::clearAddPlayTrack
Oct 19 12:58:45 volumio volumio[973]: info: Sending Spotify command with payload to local API: /player/play
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="resolved context of track" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=trace msg="emitting websocket event: will_play"
Oct 19 12:58:45 volumio volumio[973]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2c00DlvpzthGKcyXpe5GHa","play_origin":"go-librespot"}}
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="selected format OGG_VORBIS_320 (3cfe40b98b58807ed9f551295e39e2337055371e)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="requested aes key for file 3cfe40b98b58807ed9f551295e39e2337055371e, gid: 2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="fetched first chunk of 11, total size is 5473352 bytes" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:143:(_snd_pcm_volumioswitch_open_target_pcm) PCM Volumio ALSA Switch Plugin failed to open the switcher target pcm volumioLocalPlayback
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=error msg="failed handling status request" error="failed loading context: failed loading current track (load context): failed setting stream for spotify:track:2c00DlvpzthGKcyXpe5GHa: ALSA error at snd_pcm_open: Invalid argument"
Oct 19 12:58:45 volumio volumio[973]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:45 volumio go-librespot[18036]: time="2024-10-19T12:58:45+02:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:2c00DlvpzthGKcyXpe5GHa"
Oct 19 12:58:50 volumio volumio[973]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________
Oct 19 12:58:50 volumio volumio[973]: info: PLUGIN onReboot : networkfs
Oct 19 12:58:50 volumio volumio[973]: info: PLUGIN onReboot : audiophonicsonoff
Oct 19 12:58:50 volumio volumio[973]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 19 12:58:50 volumio volumio[973]: TypeError: Cannot read property 'writeSync' of undefined
Oct 19 12:58:50 volumio volumio[973]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:35:25)
Oct 19 12:58:50 volumio volumio[973]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30)
Oct 19 12:58:50 volumio volumio[973]: at HashMap. (/volumio/app/pluginmanager.js:668:31)
Oct 19 12:58:50 volumio volumio[973]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10)
Oct 19 12:58:50 volumio volumio[973]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7)
Oct 19 12:58:50 volumio volumio[973]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20)
Oct 19 12:58:50 volumio volumio[973]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22)
Oct 19 12:58:50 volumio volumio[973]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:864:33)
Oct 19 12:58:50 volumio volumio[973]: at Socket.emit (events.js:315:20)
Oct 19 12:58:50 volumio volumio[973]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Oct 19 12:58:50 volumio volumio[973]: at processTicksAndRejections (internal/process/task_queues.js:75:11)
Oct 19 12:58:50 volumio volumio[973]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Oct 19 12:58:51 volumio sudo[18217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-19 12:57
Oct 19 12:58:51 volumio sudo[18217]: 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="35b821ff7c588ea2ff28d7b2bc9bb02e49e3ab6c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="8ef80245b1f7b577b29fe08b77efdc88d53369e5"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 18 Sep 2024 02:17:42 PM CEST"
VOLUMIO_VERSION="3.758"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="cfa71b4386e95e4d11d00ae35602129a"