-- Logs begin at Wed 2024-02-21 21:42:47 CET, end at Wed 2024-04-24 14:00:57 CEST. -- Apr 24 13:59:03 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:07 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:09 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:09+02:00" level=debug msg="fetched chunk 9/15, size: 524288" Apr 24 13:59:11 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:15 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:19 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:19 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:19+02:00" level=debug msg="fetched chunk 10/15, size: 524288" Apr 24 13:59:23 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:23 volumio-rpi sudo[2467]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 24 13:59:23 volumio-rpi sudo[2467]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:23 volumio-rpi sudo[2467]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:23 volumio-rpi sudo[2469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 24 13:59:23 volumio-rpi sudo[2469]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:23 volumio-rpi sudo[2469]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:23 volumio-rpi volumio[741]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.202 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 8 Apr 24 13:59:23 volumio-rpi sudo[2473]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 24 13:59:23 volumio-rpi sudo[2473]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:23 volumio-rpi sudo[2473]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:23 volumio-rpi sudo[2476]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 24 13:59:23 volumio-rpi sudo[2476]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:23 volumio-rpi sudo[2476]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:23 volumio-rpi volumio[741]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.202 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 9 Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetVisibleSources Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:24 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 24 13:59:24 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:24 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:24 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:24 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:24 volumio-rpi volumio[741]: info: Listing playlists Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 24 13:59:24 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:24 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:25 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 13:59:25 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:25 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:25 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:25 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:25 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:25 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:25 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:26 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 13:59:26 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:26 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:26 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:26 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:26 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:26 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:26 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:27 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:30 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:30+02:00" level=debug msg="fetched chunk 11/15, size: 524288" Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=debug msg="handling pause player command from 5929e76ecf665e0da0410e71d13ef9f537725e68" Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=debug msg="pause track at 82988ms" Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=debug msg="sending successful reply for delaer request" Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 24 13:59:31 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:31+02:00" level=trace msg="emitting websocket event: paused" Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: {"status":"pause","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":82000,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:31 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:31 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":82000,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:31 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService pause Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:31 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: {"status":"pause","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":82000,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:31 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:31 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":82000,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:31 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService pause Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:31 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:31 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:31 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:34 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:34+02:00" level=debug msg="put connect state inactive" Apr 24 13:59:34 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:34+02:00" level=trace msg="emitting websocket event: inactive" Apr 24 13:59:34 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"inactive","data":null} Apr 24 13:59:34 volumio-rpi volumio[741]: error: Failed to decode event: inactive Apr 24 13:59:34 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"inactive","data":null} Apr 24 13:59:34 volumio-rpi volumio[741]: error: Failed to decode event: inactive Apr 24 13:59:36 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:36 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:36 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:36 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:36 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:36 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:36 volumio-rpi volumio[741]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.201 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 9 Apr 24 13:59:38 volumio-rpi sudo[2521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 24 13:59:38 volumio-rpi sudo[2521]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:38 volumio-rpi sudo[2521]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:38 volumio-rpi sudo[2524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 24 13:59:38 volumio-rpi sudo[2524]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 24 13:59:38 volumio-rpi sudo[2524]: pam_unix(sudo:session): session closed for user root Apr 24 13:59:38 volumio-rpi volumio[741]: verbose: New Socket.io Connection to 192.168.1.104 from 192.168.1.201 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 15_5 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Total Clients: 10 Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetVisibleSources Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:38 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 24 13:59:38 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:38 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:38 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:38 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:38 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:39 volumio-rpi volumio[741]: info: Listing playlists Apr 24 13:59:39 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 24 13:59:39 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 24 13:59:39 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 24 13:59:40 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 13:59:40 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:40 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:40 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:40 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:40 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:40 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:40 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:41 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 24 13:59:41 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:41 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:41 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:41 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:41 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:41 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:41 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 24 13:59:42 volumio-rpi volumio[741]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 24 13:59:42 volumio-rpi volumio[741]: info: Received Get System Version Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 24 13:59:42 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:42 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:42 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:42 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:47 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:47+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 24 13:59:47 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:47+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 369" Apr 24 13:59:47 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:47+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 24 13:59:47 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:47+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2885" Apr 24 13:59:49 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:49+02:00" level=debug msg="handling transfer player command from 17b460431e2f0a2a005e138a1aaeaccea0513417" Apr 24 13:59:49 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:49+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" Apr 24 13:59:49 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:49+02:00" level=debug msg="loading track spotify:track:18xvWGURVYg8hUIRHpowNr (paused: false, position: 85645ms)" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=trace msg="emitting websocket event: will_play" Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:18xvWGURVYg8hUIRHpowNr" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="requested aes key for file 1ef02ef9bd89bb587c734145a993e724cf0c1e7b, gid: 18xvWGURVYg8hUIRHpowNr" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched first chunk of 16, total size is 8203364 bytes" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 3/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 1/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 2/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 11/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 10/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 9/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="fetched chunk 8/15, size: 524288" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=trace msg="seek to 85645ms (diff: 115ms, samples: 3776944, bytes: 4315779)" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=info msg="loaded track \"Childchewer\" (uri: spotify:track:18xvWGURVYg8hUIRHpowNr, paused: false, position: 85645ms, duration: 166283ms)" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=trace msg="emitting websocket event: metadata" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=trace msg="emitting websocket event: active" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="sending successful reply for delaer request" Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","name":"Childchewer","artist_names":["Infant Annihilator"],"album_name":"The Battle of Yaldabaoth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","position":85645,"duration":166283,"release_date":"year:2019 month:9 day:11","track_number":1,"disc_number":1}} Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"active","data":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: Aligning Spotify Volume to Volumio Volume Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: Setting Spotify Volume from Volumio: 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","name":"Childchewer","artist_names":["Infant Annihilator"],"album_name":"The Battle of Yaldabaoth","album_cover_url":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","position":85645,"duration":166283,"release_date":"year:2019 month:9 day:11","track_number":1,"disc_number":1}} Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"active","data":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: Aligning Spotify Volume to Volumio Volume Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: Setting Spotify Volume from Volumio: 100 Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2799" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=trace msg="emitting websocket event: playing" Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService play Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:50 volumio-rpi volumio[741]: info: Received an update from plugin. extracting info from payload Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","play_origin":"go-librespot"}} Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService play Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:50 volumio-rpi volumio[741]: info: Received an update from plugin. extracting info from payload Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 24 13:59:50 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:50+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1952" Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService play Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:50 volumio-rpi volumio[741]: info: Received an update from plugin. extracting info from payload Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: PUSH STATE SPOTIFY Apr 24 13:59:50 volumio-rpi volumio[741]: SPOTIFY: {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Childchewer","artist":"Infant Annihilator","album":"The Battle of Yaldabaoth","albumart":"https://i.scdn.co/image/ab67616d00001e023403def0c03d9923c69e1f14","uri":"spotify:track:18xvWGURVYg8hUIRHpowNr","trackType":"spotify","seek":85645,"duration":166,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 24 13:59:50 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService play Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 13:59:50 volumio-rpi volumio[741]: info: Received an update from plugin. extracting info from payload Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 13:59:50 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:50 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 13:59:51 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:51 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 13:59:52 volumio-rpi volumio[741]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 24 13:59:52 volumio-rpi volumio[741]: info: Sending Spotify command with payload to local API: /player/volume Apr 24 13:59:52 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:52+02:00" level=debug msg="update volume to 65535/65535" Apr 24 13:59:52 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:52+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 24 13:59:52 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:52+02:00" level=trace msg="emitting websocket event: volume" Apr 24 13:59:52 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 24 13:59:52 volumio-rpi volumio[741]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 24 13:59:52 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 24 13:59:52 volumio-rpi volumio[741]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 24 13:59:53 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetQueue Apr 24 13:59:53 volumio-rpi volumio[741]: info: CoreStateMachine::getQueue Apr 24 13:59:53 volumio-rpi volumio[741]: info: CorePlayQueue::getQueue Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 24 13:59:57 volumio-rpi volumio[741]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 24 13:59:57 volumio-rpi volumio[741]: info: Received Get System Version Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 24 13:59:57 volumio-rpi volumio[741]: info: Received Get System Info Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 24 13:59:57 volumio-rpi volumio[741]: info: Discovery: Getting this device information Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetState Apr 24 13:59:57 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 13:59:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 24 13:59:58 volumio-rpi go-librespot[2387]: time="2024-04-24T13:59:58+02:00" level=debug msg="fetched chunk 12/15, size: 524288" Apr 24 14:00:09 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:09+02:00" level=debug msg="fetched chunk 13/15, size: 524288" Apr 24 14:00:09 volumio-rpi volumio[741]: info: VolumeController::SetAlsaVolume4 Apr 24 14:00:09 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:09 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:09 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 14:00:09 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:10 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 4 Apr 24 14:00:10 volumio-rpi volumio[741]: SPOTIFY: SPOTIFY VOLUME 100 Apr 24 14:00:10 volumio-rpi volumio[741]: SPOTIFY: VOLUMIO VOLUME 4 Apr 24 14:00:10 volumio-rpi volumio[741]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 24 14:00:10 volumio-rpi volumio[741]: info: Setting Spotify Volume from Volumio: 4 Apr 24 14:00:11 volumio-rpi volumio[741]: info: VolumeController::SetAlsaVolume100 Apr 24 14:00:11 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:11 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:11 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 14:00:11 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:11 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:11 volumio-rpi volumio[741]: SPOTIFY: SPOTIFY VOLUME 4 Apr 24 14:00:11 volumio-rpi volumio[741]: SPOTIFY: VOLUMIO VOLUME 100 Apr 24 14:00:11 volumio-rpi volumio[741]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 24 14:00:11 volumio-rpi volumio[741]: info: Setting Spotify Volume from Volumio: 100 Apr 24 14:00:12 volumio-rpi volumio[741]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 24 14:00:12 volumio-rpi volumio[741]: info: Sending Spotify command with payload to local API: /player/volume Apr 24 14:00:12 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:12+02:00" level=debug msg="update volume to 65535/65535" Apr 24 14:00:12 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:12+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 24 14:00:12 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:12+02:00" level=trace msg="emitting websocket event: volume" Apr 24 14:00:12 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 24 14:00:12 volumio-rpi volumio[741]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 24 14:00:12 volumio-rpi volumio[741]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 24 14:00:12 volumio-rpi volumio[741]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 24 14:00:16 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 24 14:00:19 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:19+02:00" level=debug msg="fetched chunk 14/15, size: 524288" Apr 24 14:00:29 volumio-rpi go-librespot[2387]: time="2024-04-24T14:00:29+02:00" level=debug msg="fetched chunk 15/15, size: 339044" Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: info: Retrieving Cloud Streaming UI Apr 24 14:00:35 volumio-rpi volumio[741]: info: Getting Tidal Cloud Configuration Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: info: Getting Qobuz Cloud Configuration Apr 24 14:00:35 volumio-rpi volumio[741]: info: Asking plugin for UI Config Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: info: Getting Spotify Cloud Configuration Apr 24 14:00:35 volumio-rpi volumio[741]: info: Asking plugin for UI Config Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: info: Saving Spotify Acccount Apr 24 14:00:35 volumio-rpi volumio[741]: info: Got Tidal Cloud Configuration Apr 24 14:00:35 volumio-rpi volumio[741]: info: Got it Apr 24 14:00:35 volumio-rpi volumio[741]: info: Got it Apr 24 14:00:35 volumio-rpi volumio[741]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:35 volumio-rpi volumio[741]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:35 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , updateDb Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand update Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:37 volumio-rpi volumio[741]: info: Apr 24 14:00:37 volumio-rpi volumio[741]: ---------------------------- MPD announces state update: update Apr 24 14:00:37 volumio-rpi volumio[741]: info: sendMpdCommand update took 4 milliseconds Apr 24 14:00:37 volumio-rpi volumio[741]: info: ControllerMpd::getState Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:37 volumio-rpi volumio[741]: info: Apr 24 14:00:37 volumio-rpi volumio[741]: ---------------------------- MPD announces state update: update Apr 24 14:00:37 volumio-rpi volumio[741]: info: ControllerMpd::getState Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:37 volumio-rpi volumio[741]: info: sendMpdCommand status took 9 milliseconds Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:37 volumio-rpi volumio[741]: info: Command Router : Notfying DB Updatefalse Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::Close All Modals sent Apr 24 14:00:37 volumio-rpi volumio[741]: info: sendMpdCommand status took 53 milliseconds Apr 24 14:00:37 volumio-rpi volumio[741]: info: sendMpdCommand status took 52 milliseconds Apr 24 14:00:37 volumio-rpi volumio[741]: info: sendMpdCommand status took 51 milliseconds Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:37 volumio-rpi volumio[741]: info: Command Router : Notfying DB Updatefalse Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::Close All Modals sent Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:37 volumio-rpi volumio[741]: info: ControllerMpd::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService stop Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus play Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::stPlaybackTimer Apr 24 14:00:37 volumio-rpi volumio[741]: info: ControllerMpd::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 24 14:00:37 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService stop Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus stop Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: No code Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:37 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:37 volumio-rpi volumio[741]: info: ------------------------------ 108ms Apr 24 14:00:37 volumio-rpi volumio[741]: info: ------------------------------ 122ms Apr 24 14:00:37 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:37 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:37 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:37 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:37 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:39 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:43 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:47 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: info: Retrieving Cloud Streaming UI Apr 24 14:00:52 volumio-rpi volumio[741]: info: Getting Tidal Cloud Configuration Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: info: Getting Qobuz Cloud Configuration Apr 24 14:00:52 volumio-rpi volumio[741]: info: Asking plugin for UI Config Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: info: Getting Spotify Cloud Configuration Apr 24 14:00:52 volumio-rpi volumio[741]: info: Asking plugin for UI Config Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: info: Saving Spotify Acccount Apr 24 14:00:52 volumio-rpi volumio[741]: info: Got Tidal Cloud Configuration Apr 24 14:00:52 volumio-rpi volumio[741]: info: Got it Apr 24 14:00:52 volumio-rpi volumio[741]: info: Got it Apr 24 14:00:52 volumio-rpi volumio[741]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 24 14:00:52 volumio-rpi volumio[741]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioGetBrowseSources Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:52 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Apr 24 14:00:54 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand rescan Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:54 volumio-rpi volumio[741]: info: Apr 24 14:00:54 volumio-rpi volumio[741]: ---------------------------- MPD announces state update: update Apr 24 14:00:54 volumio-rpi volumio[741]: info: sendMpdCommand rescan took 6 milliseconds Apr 24 14:00:54 volumio-rpi volumio[741]: info: ControllerMpd::getState Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:54 volumio-rpi volumio[741]: info: Apr 24 14:00:54 volumio-rpi volumio[741]: ---------------------------- MPD announces state update: update Apr 24 14:00:54 volumio-rpi volumio[741]: info: ControllerMpd::getState Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::sendMpdCommand status Apr 24 14:00:54 volumio-rpi volumio[741]: info: sendMpdCommand status took 3 milliseconds Apr 24 14:00:54 volumio-rpi volumio[741]: info: sendMpdCommand status took 2 milliseconds Apr 24 14:00:54 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:54 volumio-rpi volumio[741]: info: Command Router : Notfying DB Updatefalse Apr 24 14:00:54 volumio-rpi volumio[741]: info: CoreCommandRouter::Close All Modals sent Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:55 volumio-rpi volumio[741]: info: ControllerMpd::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService stop Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus stop Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: No code Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: ------------------------------ 57ms Apr 24 14:00:55 volumio-rpi volumio[741]: info: sendMpdCommand status took 56 milliseconds Apr 24 14:00:55 volumio-rpi volumio[741]: info: sendMpdCommand status took 56 milliseconds Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:55 volumio-rpi volumio[741]: info: Command Router : Notfying DB Updatefalse Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::Close All Modals sent Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: ControllerMpd::parseState Apr 24 14:00:55 volumio-rpi volumio[741]: info: ControllerMpd::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::servicePushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 24 14:00:55 volumio-rpi volumio[741]: verbose: CURRENT POSITION 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::syncState stateService stop Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::syncState currentStatus stop Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: No code Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreStateMachine::pushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: CorePlayQueue::getTrack 0 Apr 24 14:00:55 volumio-rpi volumio[741]: info: CoreCommandRouter::volumioPushState Apr 24 14:00:55 volumio-rpi volumio[741]: info: ------------------------------ 110ms Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:55 volumio-rpi volumio[741]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 24 14:00:56 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Apr 24 14:00:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares Apr 24 14:00:57 volumio-rpi volumio[741]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService Apr 24 14:00:57 volumio-rpi volumio[741]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 14:00:57 volumio-rpi volumio[741]: Error: getaddrinfo -3007 Apr 24 14:00:57 volumio-rpi volumio[741]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11) Apr 24 14:00:57 volumio-rpi volumio[741]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10) Apr 24 14:00:57 volumio-rpi volumio[741]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) { Apr 24 14:00:57 volumio-rpi volumio[741]: code: -3007, Apr 24 14:00:57 volumio-rpi volumio[741]: errno: -3007, Apr 24 14:00:57 volumio-rpi volumio[741]: syscall: 'getaddrinfo' Apr 24 14:00:57 volumio-rpi volumio[741]: } Apr 24 14:00:57 volumio-rpi volumio[741]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 24 14:00:57 volumio-rpi sudo[2600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-24 13:59 Apr 24 14:00:57 volumio-rpi sudo[2600]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"