-- Logs begin at Tue 2025-10-21 22:14:46 CEST, end at Fri 2025-10-24 08:55:14 CEST. -- Oct 24 08:54:02 sleep go-librespot[30809]: time="2025-10-24T08:54:02+02:00" level=trace msg="sent dealer ping" Oct 24 08:54:02 sleep go-librespot[30809]: time="2025-10-24T08:54:02+02:00" level=trace msg="received dealer pong" Oct 24 08:54:06 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:06 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:06 sleep go-librespot[30809]: time="2025-10-24T08:54:06+02:00" level=debug msg="fetched chunk 17/17, size: 365560" uri="spotify:track:3ZYlHhwB1YnzenzkURxprc" Oct 24 08:54:08 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:08 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:08 sleep sudo[2162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 24 08:54:08 sleep sudo[2160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 24 08:54:08 sleep sudo[2162]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 24 08:54:08 sleep sudo[2160]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 24 08:54:08 sleep sudo[2162]: pam_unix(sudo:session): session closed for user root Oct 24 08:54:08 sleep sudo[2160]: pam_unix(sudo:session): session closed for user root Oct 24 08:54:08 sleep volumio[979]: verbose: New Socket.io Connection to 192.168.2.220 from 192.168.2.147 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP3A.251005.004.B1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.97 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Oct 24 08:54:09 sleep sudo[2166]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 24 08:54:09 sleep sudo[2166]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 24 08:54:09 sleep sudo[2166]: pam_unix(sudo:session): session closed for user root Oct 24 08:54:09 sleep sudo[2169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 24 08:54:09 sleep sudo[2169]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 24 08:54:09 sleep sudo[2169]: pam_unix(sudo:session): session closed for user root Oct 24 08:54:09 sleep volumio[979]: verbose: New Socket.io Connection to 192.168.2.220 from 192.168.2.147 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP3A.251005.004.B1; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/141.0.7390.97 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::volumioGetVisibleSources Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:09 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 24 08:54:09 sleep volumio[979]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 24 08:54:09 sleep volumio[979]: info: Received Get System Info Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:09 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:09 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:09 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:09 sleep volumio[979]: info: Listing playlists Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 24 08:54:09 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 24 08:54:11 sleep volumio[979]: info: Received Get System Info Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:11 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:11 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:11 sleep nmbd[747]: [2025/10/24 08:54:11.090202, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Oct 24 08:54:11 sleep nmbd[747]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.2.220 for name WORKGROUP<1d>. Oct 24 08:54:11 sleep nmbd[747]: This response was from IP 192.168.2.206, reporting an IP address of 192.168.2.206. Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 24 08:54:11 sleep volumio[979]: info: Received Get System Info Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:11 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:11 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:11 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:12 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 24 08:54:12 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 24 08:54:15 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:15 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:15 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:15 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:15 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:15 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:16 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:16 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:16 sleep volumio[979]: info: Listing playlists Oct 24 08:54:16 sleep volumio[979]: info: Listing playlists Oct 24 08:54:19 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 24 08:54:24 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 24 08:54:26 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:26 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:27 sleep go-librespot[30809]: time="2025-10-24T08:54:27+02:00" level=debug msg="prefetching next track" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:27 sleep go-librespot[30809]: time="2025-10-24T08:54:27+02:00" level=debug msg="selected format OGG_VORBIS_320 (38ef496ef3b5d0e38dd870bf0f5302f5b4c8ac65)" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:27 sleep go-librespot[30809]: time="2025-10-24T08:54:27+02:00" level=debug msg="requested aes key for file 38ef496ef3b5d0e38dd870bf0f5302f5b4c8ac65, gid: 2pqOzcIb5brplvGzofn99C" Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 24 08:54:27 sleep volumio[979]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 24 08:54:27 sleep volumio[979]: info: Received Get System Version Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 24 08:54:27 sleep go-librespot[30809]: time="2025-10-24T08:54:27+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:27 sleep volumio[979]: info: Received Get System Info Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:27 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:27 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:27 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:28 sleep go-librespot[30809]: time="2025-10-24T08:54:28+02:00" level=debug msg="fetched first chunk of 10, total size is 5067120 bytes" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:28 sleep go-librespot[30809]: time="2025-10-24T08:54:28+02:00" level=info msg="prefetched track \"Johanna's Dream\" (duration: 143960ms)" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:28 sleep go-librespot[30809]: time="2025-10-24T08:54:28+02:00" level=debug msg="fetched chunk 2/9, size: 524288" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:28 sleep go-librespot[30809]: time="2025-10-24T08:54:28+02:00" level=debug msg="fetched chunk 1/9, size: 524288" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:28 sleep go-librespot[30809]: time="2025-10-24T08:54:28+02:00" level=debug msg="fetched chunk 3/9, size: 524288" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:32 sleep go-librespot[30809]: time="2025-10-24T08:54:32+02:00" level=trace msg="sent dealer ping" Oct 24 08:54:32 sleep go-librespot[30809]: time="2025-10-24T08:54:32+02:00" level=trace msg="received dealer pong" Oct 24 08:54:36 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:36 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:36 sleep volumio[979]: info: Listing playlists Oct 24 08:54:36 sleep volumio[979]: info: Listing playlists Oct 24 08:54:37 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 24 08:54:41 sleep volumio[979]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ampswitch/volumio/buster/armhf Oct 24 08:54:44 sleep volumio[979]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/ampswitch/volumio/buster/armhf Oct 24 08:54:44 sleep volumio[979]: info: Folder /tmp/plugins removed Oct 24 08:54:44 sleep volumio[979]: info: Check plugin dependencies Oct 24 08:54:44 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 24 08:54:44 sleep volumio[979]: info: Checking if plugin already exists Oct 24 08:54:44 sleep volumio[979]: info: Rename folder Oct 24 08:54:44 sleep volumio[979]: info: Folder /tmp/downloaded_plugin.zip removed Oct 24 08:54:44 sleep volumio[979]: info: Move to category Oct 24 08:54:44 sleep volumio[979]: info: Checking if install.sh is present Oct 24 08:54:44 sleep volumio[979]: info: Executing install.sh Oct 24 08:54:45 sleep sudo[2251]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/system_controller/ampswitch/install.sh Oct 24 08:54:45 sleep sudo[2251]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 24 08:54:45 sleep sudo[2251]: pam_unix(sudo:session): session closed for user root Oct 24 08:54:45 sleep volumio[979]: Plugin install end detected on script Oct 24 08:54:45 sleep volumio[979]: info: Install script completed Oct 24 08:54:45 sleep volumio[979]: info: Adding reference to registry Oct 24 08:54:45 sleep volumio[979]: info: Done installing plugin. Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 24 08:54:45 sleep volumio[979]: info: Folder /tmp/plugins removed Oct 24 08:54:45 sleep volumio[979]: info: Folder /tmp/downloaded_plugin.zip removed Oct 24 08:54:45 sleep volumio[979]: info: Folder /data/temp removed Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 24 08:54:45 sleep volumio[979]: info: Discovery: Getting this device information Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:45 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:45 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 24 08:54:46 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:46 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:50 sleep volumio[979]: info: Enabling plugin ampswitch Oct 24 08:54:50 sleep volumio[979]: info: Loading plugin "ampswitch"... Oct 24 08:54:51 sleep volumio[979]: info: PLUGIN START: ampswitch Oct 24 08:54:51 sleep volumio[979]: info: Done. Oct 24 08:54:51 sleep volumio[979]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11 Oct 24 08:54:51 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:51 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] CurState: play PrevState: na Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Togle GPIO: ON Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] CurState: play PrevState: play Oct 24 08:54:51 sleep volumio[979]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Setting UI defaults Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Port: 24 Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Inverted: false Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Latched: false Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] On pulse width: 500 Oct 24 08:54:51 sleep volumio[979]: info: [ASDebug] Off pulse width: 500 Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=trace msg="emitting websocket event: not_playing" Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:3ZYlHhwB1YnzenzkURxprc","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: error: Failed to decode event: not_playing Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:3ZYlHhwB1YnzenzkURxprc","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: error: Failed to decode event: not_playing Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:3ZYlHhwB1YnzenzkURxprc","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: error: Failed to decode event: not_playing Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:3ZYlHhwB1YnzenzkURxprc","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: error: Failed to decode event: not_playing Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=trace msg="emitting websocket event: will_play" Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","play_origin":"playlist"}} Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=info msg="loaded track \"Johanna's Dream\" (paused: false, position: 0ms, duration: 143960ms, prefetched: true)" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","play_origin":"playlist"}} Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=trace msg="scheduling prefetch in 114s" Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=trace msg="emitting websocket event: metadata" Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2pqOzcIb5brplvGzofn99C","name":"Johanna's Dream","artist_names":["BALTHVS"],"album_name":"MACROCOSM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","position":0,"duration":143960,"release_date":"year:2020 month:9 day:5","track_number":2,"disc_number":1}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2pqOzcIb5brplvGzofn99C","name":"Johanna's Dream","artist_names":["BALTHVS"],"album_name":"MACROCOSM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","position":0,"duration":143960,"release_date":"year:2020 month:9 day:5","track_number":2,"disc_number":1}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2pqOzcIb5brplvGzofn99C","name":"Johanna's Dream","artist_names":["BALTHVS"],"album_name":"MACROCOSM","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","position":0,"duration":143960,"release_date":"year:2020 month:9 day:5","track_number":2,"disc_number":1}} Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 24 08:54:55 sleep go-librespot[30809]: time="2025-10-24T08:54:55+02:00" level=trace msg="emitting websocket event: playing" Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","resume":false,"play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:55 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:55 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:55 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","resume":false,"play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:55 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:55 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:55 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","resume":false,"play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:55 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:55 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:55 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E4CNz1YWfolbF","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","resume":false,"play_origin":"playlist"}} Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:55 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:55 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:55 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:55 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:56 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:56 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:56 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:56 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:56 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:56 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:56 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:56 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:56 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: PUSH STATE SPOTIFY Oct 24 08:54:56 sleep volumio[979]: SPOTIFY: {"status":"play","service":"spop","title":"Johanna's Dream","artist":"BALTHVS","album":"MACROCOSM","albumart":"https://i.scdn.co/image/ab67616d00001e0284b439f9aac553986ced7d26","uri":"spotify:track:2pqOzcIb5brplvGzofn99C","trackType":"spotify","seek":0,"duration":143,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Oct 24 08:54:56 sleep volumio[979]: info: CoreCommandRouter::servicePushState Oct 24 08:54:56 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:56 sleep volumio[979]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current tidal Received spop Oct 24 08:54:56 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:54:56 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:54:56 sleep volumio[979]: info: Listing playlists Oct 24 08:54:56 sleep volumio[979]: info: Listing playlists Oct 24 08:55:02 sleep go-librespot[30809]: time="2025-10-24T08:55:02+02:00" level=trace msg="received accesspoint ping" Oct 24 08:55:02 sleep go-librespot[30809]: time="2025-10-24T08:55:02+02:00" level=trace msg="received accesspoint pong ack" Oct 24 08:55:02 sleep go-librespot[30809]: time="2025-10-24T08:55:02+02:00" level=trace msg="sent dealer ping" Oct 24 08:55:02 sleep go-librespot[30809]: time="2025-10-24T08:55:02+02:00" level=trace msg="received dealer pong" Oct 24 08:55:05 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 24 08:55:05 sleep volumio[979]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 24 08:55:07 sleep volumio[979]: info: CoreCommandRouter::volumioGetState Oct 24 08:55:07 sleep volumio[979]: info: CorePlayQueue::getTrack 0 Oct 24 08:55:08 sleep volumio[979]: info: Starting Uninstall of plugin system_controller - ampswitch Oct 24 08:55:08 sleep volumio[979]: info: Uninstalling plugin ampswitch Oct 24 08:55:08 sleep volumio[979]: info: [ASDebug] Port: 24 Oct 24 08:55:08 sleep volumio[979]: info: [ASDebug] Inverted: false Oct 24 08:55:08 sleep volumio[979]: info: [ASDebug] Delay: 720 Oct 24 08:55:10 sleep go-librespot[30809]: time="2025-10-24T08:55:10+02:00" level=debug msg="fetched chunk 4/9, size: 524288" uri="spotify:track:2pqOzcIb5brplvGzofn99C" Oct 24 08:55:13 sleep volumio[979]: info: [ASDebug] Port: 24 Oct 24 08:55:13 sleep volumio[979]: info: [ASDebug] Inverted: false Oct 24 08:55:13 sleep volumio[979]: info: [ASDebug] Delay: 720 Oct 24 08:55:13 sleep volumio[979]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 24 08:55:13 sleep volumio[979]: Error: EBADF: bad file descriptor, close Oct 24 08:55:13 sleep volumio[979]: at Object.closeSync (fs.js:439:3) Oct 24 08:55:13 sleep volumio[979]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Oct 24 08:55:13 sleep volumio[979]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Oct 24 08:55:13 sleep volumio[979]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Oct 24 08:55:13 sleep volumio[979]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Oct 24 08:55:13 sleep volumio[979]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Oct 24 08:55:13 sleep volumio[979]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Oct 24 08:55:13 sleep volumio[979]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Oct 24 08:55:13 sleep volumio[979]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) Oct 24 08:55:13 sleep volumio[979]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) Oct 24 08:55:13 sleep volumio[979]: at Socket.emit (events.js:315:20) Oct 24 08:55:13 sleep volumio[979]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 24 08:55:13 sleep volumio[979]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Oct 24 08:55:13 sleep volumio[979]: errno: -9, Oct 24 08:55:13 sleep volumio[979]: syscall: 'close', Oct 24 08:55:13 sleep volumio[979]: code: 'EBADF' Oct 24 08:55:13 sleep volumio[979]: } Oct 24 08:55:13 sleep volumio[979]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 24 08:55:14 sleep sudo[2361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-24 08:54 Oct 24 08:55:14 sleep sudo[2361]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"