-- Logs begin at Tue 2025-11-04 03:00:00 CET, end at Tue 2025-11-04 20:49:20 CET. --
Nov 04 20:48:04 volumio go-librespot[1232]: time="2025-11-04T20:48:04+01:00" level=trace msg="sent dealer ping"
Nov 04 20:48:04 volumio go-librespot[1232]: time="2025-11-04T20:48:04+01:00" level=trace msg="received dealer pong"
Nov 04 20:48:07 volumio volumio[1026]: info: CALLMETHOD: music_service mpd savePlaybackOptions [object Object]
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , savePlaybackOptions
Nov 04 20:48:07 volumio sudo[16500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Nov 04 20:48:07 volumio sudo[16500]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 04 20:48:07 volumio sudo[16500]: pam_unix(sudo:session): session closed for user root
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio sudo[16503]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Nov 04 20:48:07 volumio sudo[16503]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Nov 04 20:48:07 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:07 volumio systemd[1]: Stopping Music Player Daemon...
Nov 04 20:48:07 volumio volumio[1026]: info: MPD Permissions set
Nov 04 20:48:07 volumio systemd[1]: mpd.service: Succeeded.
Nov 04 20:48:07 volumio systemd[1]: Stopped Music Player Daemon.
Nov 04 20:48:07 volumio systemd[1]: Starting Music Player Daemon...
Nov 04 20:48:07 volumio sudo[16509]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Nov 04 20:48:07 volumio sudo[16509]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 04 20:48:07 volumio sudo[16509]: pam_unix(sudo:session): session closed for user root
Nov 04 20:48:08 volumio mpd[16511]: Nov 04 20:48 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Nov 04 20:48:08 volumio systemd[1]: Started Music Player Daemon.
Nov 04 20:48:08 volumio sudo[16503]: pam_unix(sudo:session): session closed for user root
Nov 04 20:48:08 volumio volumio[1026]: error: updateQueue error: null
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Nov 04 20:48:09 volumio volumio[1026]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Nov 04 20:48:09 volumio volumio[1026]: info: Received Get System Version
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Nov 04 20:48:09 volumio volumio[1026]: info: Received Get System Info
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Nov 04 20:48:09 volumio volumio[1026]: info: Discovery: Getting this device information
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::volumioGetState
Nov 04 20:48:09 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Nov 04 20:48:11 volumio go-librespot[1232]: time="2025-11-04T20:48:11+01:00" level=debug msg="fetched chunk 13/14, size: 524288" uri="spotify:track:6CZxZdssLXDVEykOehJUuo"
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: info: Retrieving Cloud Streaming UI
Nov 04 20:48:20 volumio volumio[1026]: info: Getting Tidal Cloud Configuration
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: info: Getting Qobuz Cloud Configuration
Nov 04 20:48:20 volumio volumio[1026]: info: Asking plugin for UI Config
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: info: Getting Spotify Cloud Configuration
Nov 04 20:48:20 volumio volumio[1026]: info: Asking plugin for UI Config
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: info: Saving Spotify Acccount
Nov 04 20:48:20 volumio volumio[1026]: info: Got Tidal Cloud Configuration
Nov 04 20:48:20 volumio volumio[1026]: info: Got it
Nov 04 20:48:20 volumio volumio[1026]: info: Got it
Nov 04 20:48:20 volumio volumio[1026]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::getUIConfigOnPlugin
Nov 04 20:48:20 volumio volumio[1026]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::volumioGetBrowseSources
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::volumioGetBrowseSources
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::volumioGetBrowseSources
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:20 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Nov 04 20:48:24 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:25 volumio go-librespot[1232]: time="2025-11-04T20:48:25+01:00" level=debug msg="fetched chunk 14/14, size: 71465" uri="spotify:track:6CZxZdssLXDVEykOehJUuo"
Nov 04 20:48:26 volumio volumio[1026]: info: Enabling MyMusic plugin airplay_emulation
Nov 04 20:48:26 volumio volumio[1026]: info: Enabling plugin airplay_emulation
Nov 04 20:48:26 volumio volumio[1026]: info: Loading plugin "airplay_emulation"...
Nov 04 20:48:26 volumio volumio[1026]: info: Starting Shairport Sync
Nov 04 20:48:26 volumio volumio[1026]: info: PLUGIN START: airplay_emulation
Nov 04 20:48:26 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:26 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Nov 04 20:48:26 volumio volumio[1026]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Nov 04 20:48:26 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Nov 04 20:48:26 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Nov 04 20:48:26 volumio volumio[1026]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Nov 04 20:48:26 volumio volumio[1026]: info: Done.
Nov 04 20:48:26 volumio volumio[1026]: info: Starting Shairport Sync
Nov 04 20:48:26 volumio volumio[1026]: info: Starting Shairport Sync
Nov 04 20:48:26 volumio sudo[16590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Nov 04 20:48:26 volumio sudo[16590]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 04 20:48:27 volumio sudo[16593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Nov 04 20:48:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Nov 04 20:48:27 volumio sudo[16593]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 04 20:48:27 volumio systemd[1]: shairport-sync.service: Succeeded.
Nov 04 20:48:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Nov 04 20:48:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Nov 04 20:48:27 volumio sudo[16590]: pam_unix(sudo:session): session closed for user root
Nov 04 20:48:27 volumio volumio[1026]: info: Shairport-Sync Started
Nov 04 20:48:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Nov 04 20:48:27 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
Nov 04 20:48:27 volumio systemd[1]: shairport-sync.service: Succeeded.
Nov 04 20:48:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Nov 04 20:48:27 volumio volumio[1026]: Error adding Membership: Error: addMembership EINVAL
Nov 04 20:48:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Nov 04 20:48:27 volumio sudo[16593]: pam_unix(sudo:session): session closed for user root
Nov 04 20:48:27 volumio volumio[1026]: info: Shairport-Sync Started
Nov 04 20:48:28 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:32 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=trace msg="sent dealer ping"
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=trace msg="received dealer pong"
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=debug msg="prefetching next track" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=debug msg="selected format OGG_VORBIS_320 (693f74c9fa18ed6bd8ed1a907fb9c930e67d774f)" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=debug msg="requested aes key for file 693f74c9fa18ed6bd8ed1a907fb9c930e67d774f, gid: 15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:34 volumio go-librespot[1232]: time="2025-11-04T20:48:34+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:35 volumio go-librespot[1232]: time="2025-11-04T20:48:35+01:00" level=debug msg="fetched first chunk of 19, total size is 9511449 bytes" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:35 volumio go-librespot[1232]: time="2025-11-04T20:48:35+01:00" level=info msg="prefetched track \"Madame Tussauds\" (duration: 217186ms)" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:35 volumio go-librespot[1232]: time="2025-11-04T20:48:35+01:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:35 volumio go-librespot[1232]: time="2025-11-04T20:48:35+01:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:35 volumio go-librespot[1232]: time="2025-11-04T20:48:35+01:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:48:36 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:37 volumio volumio[1026]: info: Enabling MyMusic plugin bluetooth
Nov 04 20:48:37 volumio volumio[1026]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth
Nov 04 20:48:37 volumio volumio[1026]: info: [MyVolumio PluginManager] Plugin audio_interface bluetooth not in user plan, not enabling
Nov 04 20:48:37 volumio volumio[1026]: info: Error: Plugin audio_interface bluetooth not in user plan, not enabling
Nov 04 20:48:37 volumio volumio[1026]: error: Could not Enable MyMusic Plugin: Error
Nov 04 20:48:40 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:45 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:47 volumio volumio[1026]: info: CALLMETHOD: miscellanea albumart clearAlbumartCache
Nov 04 20:48:47 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: albumart , clearAlbumartCache
Nov 04 20:48:47 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , rebuildAlbumCache
Nov 04 20:48:47 volumio volumio[1026]: info: Rebuild Album cache
Nov 04 20:48:49 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:53 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:57 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:48:59 volumio wpa_supplicant[898]: RRM: Ignoring radio measurement request: Not RRM network
Nov 04 20:49:01 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="emitting websocket event: not_playing"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: received: {"type":"not_playing","data":{"uri":"spotify:track:6CZxZdssLXDVEykOehJUuo","play_origin":"home"}}
Nov 04 20:49:04 volumio volumio[1026]: error: Failed to decode event: not_playing
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="emitting websocket event: will_play"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=info msg="loaded track \"Madame Tussauds\" (paused: false, position: 0ms, duration: 217186ms, prefetched: true)" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:15r64Red3tBAIc45c5yo6v","play_origin":"home"}}
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="scheduling prefetch in 187s"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="emitting websocket event: metadata"
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:15r64Red3tBAIc45c5yo6v","name":"Madame Tussauds","artist_names":["Von Wegen Lisbeth"],"album_name":"Madame Tussauds","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021ed28634a1c04a9e77e6e838","position":0,"duration":217186,"release_date":"year:2025 month:10 day:3","track_number":1,"disc_number":1}}
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="emitting websocket event: playing"
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:15r64Red3tBAIc45c5yo6v","resume":false,"play_origin":"home"}}
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: PUSH STATE SPOTIFY
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: {"status":"play","service":"spop","title":"Madame Tussauds","artist":"Von Wegen Lisbeth","album":"Madame Tussauds","albumart":"https://i.scdn.co/image/ab67616d00001e021ed28634a1c04a9e77e6e838","uri":"spotify:track:15r64Red3tBAIc45c5yo6v","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::servicePushState
Nov 04 20:49:04 volumio volumio[1026]: info: CoreStateMachine::pushState
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::volumioPushState
Nov 04 20:49:04 volumio volumio[1026]: info: [ASDebug] CurState: play PrevState: play
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="sent dealer ping"
Nov 04 20:49:04 volumio go-librespot[1232]: time="2025-11-04T20:49:04+01:00" level=trace msg="received dealer pong"
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: PUSH STATE SPOTIFY
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: {"status":"play","service":"spop","title":"Madame Tussauds","artist":"Von Wegen Lisbeth","album":"Madame Tussauds","albumart":"https://i.scdn.co/image/ab67616d00001e021ed28634a1c04a9e77e6e838","uri":"spotify:track:15r64Red3tBAIc45c5yo6v","trackType":"spotify","seek":0,"duration":217,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::servicePushState
Nov 04 20:49:04 volumio volumio[1026]: info: CoreStateMachine::pushState
Nov 04 20:49:04 volumio volumio[1026]: info: CoreCommandRouter::volumioPushState
Nov 04 20:49:04 volumio volumio[1026]: info: [ASDebug] CurState: play PrevState: play
Nov 04 20:49:04 volumio volumio[1026]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Nov 04 20:49:05 volumio go-librespot[1232]: time="2025-11-04T20:49:05+01:00" level=trace msg="received accesspoint ping"
Nov 04 20:49:05 volumio go-librespot[1232]: time="2025-11-04T20:49:05+01:00" level=trace msg="received accesspoint pong ack"
Nov 04 20:49:15 volumio volumio[1026]: info: [ASDebug] Port: 24
Nov 04 20:49:15 volumio volumio[1026]: info: [ASDebug] Inverted: false
Nov 04 20:49:15 volumio volumio[1026]: info: [ASDebug] Delay: 720
Nov 04 20:49:16 volumio go-librespot[1232]: time="2025-11-04T20:49:16+01:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:15r64Red3tBAIc45c5yo6v"
Nov 04 20:49:20 volumio volumio[1026]: info: Starting Uninstall of plugin system_controller - ampswitch
Nov 04 20:49:20 volumio volumio[1026]: info: Uninstalling plugin ampswitch
Nov 04 20:49:20 volumio volumio[1026]: info: [ASDebug] Port: 24
Nov 04 20:49:20 volumio volumio[1026]: info: [ASDebug] Inverted: false
Nov 04 20:49:20 volumio volumio[1026]: info: [ASDebug] Delay: 720
Nov 04 20:49:20 volumio volumio[1026]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Nov 04 20:49:20 volumio volumio[1026]: Error: EBADF: bad file descriptor, close
Nov 04 20:49:20 volumio volumio[1026]: at Object.closeSync (fs.js:439:3)
Nov 04 20:49:20 volumio volumio[1026]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20)
Nov 04 20:49:20 volumio volumio[1026]: at Object.closeSync (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27)
Nov 04 20:49:20 volumio volumio[1026]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8)
Nov 04 20:49:20 volumio volumio[1026]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19)
Nov 04 20:49:20 volumio volumio[1026]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10)
Nov 04 20:49:20 volumio volumio[1026]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30)
Nov 04 20:49:20 volumio volumio[1026]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10)
Nov 04 20:49:20 volumio volumio[1026]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22)
Nov 04 20:49:20 volumio volumio[1026]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45)
Nov 04 20:49:20 volumio volumio[1026]: at Socket.emit (events.js:315:20)
Nov 04 20:49:20 volumio volumio[1026]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Nov 04 20:49:20 volumio volumio[1026]: at processTicksAndRejections (internal/process/task_queues.js:75:11) {
Nov 04 20:49:20 volumio volumio[1026]: errno: -9,
Nov 04 20:49:20 volumio volumio[1026]: syscall: 'close',
Nov 04 20:49:20 volumio volumio[1026]: code: 'EBADF'
Nov 04 20:49:20 volumio volumio[1026]: }
Nov 04 20:49:20 volumio volumio[1026]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Nov 04 20:49:20 volumio sudo[16730]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-11-04 20:48
Nov 04 20:49:20 volumio sudo[16730]: 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"