-- Logs begin at Fri 2025-12-26 14:39:33 CET, end at Fri 2025-12-26 14:50:28 CET. --
Dec 26 14:49:00 volumio volumio[1126]: info: drc is already the newest version (3.2.2~dfsg0-2).
Dec 26 14:49:00 volumio sudo[3823]: pam_unix(sudo:session): session closed for user root
Dec 26 14:49:00 volumio sudo[3500]: pam_unix(sudo:session): session closed for user root
Dec 26 14:49:00 volumio volumio[1126]: info: 0 upgraded, 0 newly installed, 0 to remove and 81 not upgraded.
Dec 26 14:49:00 volumio volumio[1126]: info: Install script completed
Dec 26 14:49:00 volumio volumio[1126]: info: Done installing plugin.
Dec 26 14:49:00 volumio volumio[1126]: info: Enabling plugin fusiondsp
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 26 14:49:00 volumio volumio[1126]: info: [{"prettyName":"FusionDsp","name":"fusiondsp","category":"audio_interface","version":"1.0.62","icon":"fa-sliders fa-rotate-90","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.3.0","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":false},{"prettyName":"System information","name":"Systeminfo","category":"user_interface","version":"3.0.6","icon":"fa-info-circle","isManuallyInstalled":false,"enabled":true,"active":true}]
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 26 14:49:00 volumio volumio[1126]: info: Folder /tmp/plugins removed
Dec 26 14:49:00 volumio volumio[1126]: info: Folder /tmp/downloaded_plugin.zip removed
Dec 26 14:49:00 volumio volumio[1126]: Plugin install end detected on script
Dec 26 14:49:00 volumio volumio[1126]: info: Folder /data/temp removed
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:00 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:04 volumio kernel: hwmon hwmon2: Voltage normalised
Dec 26 14:49:18 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 26 14:49:46 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:46 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Dec 26 14:49:46 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 26 14:49:46 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Dec 26 14:49:47 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Dec 26 14:49:51 volumio volumio[1126]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object]
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::volumioGetState
Dec 26 14:49:51 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:51 volumio volumio[1126]: info: Restoring Previous Volume level: 100 false true
Dec 26 14:49:51 volumio volumio[1126]: info: VolumeController::SetAlsaVolume100
Dec 26 14:49:51 volumio volumio[1126]: info: Volume configurations have been set
Dec 26 14:49:51 volumio vtcs[2854]: [2025-12-26 14:49:51.772] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE
Dec 26 14:49:51 volumio vtcs[2854]: [2025-12-26 14:49:51.772] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected
Dec 26 14:49:51 volumio sudo[3951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:49:51 volumio sudo[3951]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:49:51 volumio systemd[1]: Stopping Volumio Tidal Connect Service...
Dec 26 14:49:51 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM
Dec 26 14:49:51 volumio systemd[1]: vtcs.service: Succeeded.
Dec 26 14:49:51 volumio systemd[1]: Stopped Volumio Tidal Connect Service.
Dec 26 14:49:51 volumio sudo[3951]: pam_unix(sudo:session): session closed for user root
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::volumioUpdateVolumeSettings
Dec 26 14:49:51 volumio volumio[1126]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume
Dec 26 14:49:51 volumio volumio[1126]: info: Disabling external Volume Control
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:49:51 volumio volumio[1126]: info: CoreStateMachine::pushState
Dec 26 14:49:51 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::volumioPushState
Dec 26 14:49:51 volumio volumio[1126]: info: CoreStateMachine::pushState
Dec 26 14:49:51 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::volumioPushState
Dec 26 14:49:51 volumio sudo[3964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:49:51 volumio sudo[3964]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:49:51 volumio sudo[3964]: pam_unix(sudo:session): session closed for user root
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Dec 26 14:49:51 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Dec 26 14:49:54 volumio volumio[1126]: info: TidalConnect service stoped!
Dec 26 14:49:54 volumio volumio[1126]: info: TidalConnect service stoped!
Dec 26 14:49:54 volumio volumio[1126]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Dec 26 14:49:54 volumio volumio[1126]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect
Dec 26 14:49:54 volumio sudo[3980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Dec 26 14:49:54 volumio sudo[3980]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:49:54 volumio systemd[1]: Started Volumio Tidal Connect Service.
Dec 26 14:49:54 volumio sudo[3980]: pam_unix(sudo:session): session closed for user root
Dec 26 14:49:55 volumio volumio[1126]: info: Executing endpoint tc_getconfig
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Dec 26 14:49:55 volumio vtcs[3982]: STARTING TidalConnect services, version: 1.5.2.56
Dec 26 14:49:55 volumio vtcs[3982]: STARTED TidalConnect services.
Dec 26 14:49:55 volumio volumio[1126]: info: Executing endpoint tc_connect
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Dec 26 14:49:55 volumio volumio[1126]: info: Connecting to TidalConnect
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::servicePushState
Dec 26 14:49:55 volumio volumio[1126]: info: CoreStateMachine::pushState
Dec 26 14:49:55 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::volumioPushState
Dec 26 14:49:55 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:55 volumio volumio[1126]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::servicePushState
Dec 26 14:49:55 volumio volumio[1126]: info: CoreStateMachine::pushState
Dec 26 14:49:55 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:55 volumio volumio[1126]: info: CoreCommandRouter::volumioPushState
Dec 26 14:49:55 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:55 volumio volumio[1126]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received tidalconnect
Dec 26 14:49:56 volumio volumio[1126]: info: VolumeController::SetAlsaVolume100
Dec 26 14:49:56 volumio volumio[1126]: info: CoreStateMachine::pushState
Dec 26 14:49:56 volumio volumio[1126]: info: CorePlayQueue::getTrack 0
Dec 26 14:49:56 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 26 14:49:56 volumio volumio[1126]: info: CoreCommandRouter::volumioPushState
Dec 26 14:49:57 volumio volumio[1126]: info: TidalConnect service started!
Dec 26 14:50:11 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 26 14:50:11 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 26 14:50:11 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:11 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:11 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:17 volumio volumio[1126]: info: Enabling plugin spop
Dec 26 14:50:17 volumio volumio[1126]: info: Loading plugin "spop"...
Dec 26 14:50:17 volumio volumio[1126]: info: PLUGIN START: spop
Dec 26 14:50:17 volumio volumio[1126]: info: Creating Spotify config file
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:17 volumio volumio[1126]: info: Done.
Dec 26 14:50:17 volumio volumio[1126]: info: Spotify config file written
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:17 volumio volumio[1126]: info: No need to fix Spotify hosts
Dec 26 14:50:17 volumio sudo[4052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 26 14:50:17 volumio sudo[4052]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:17 volumio systemd[1]: Started go-librespot Daemon.
Dec 26 14:50:17 volumio go-librespot[4054]: go-librespot daemon starting...
Dec 26 14:50:17 volumio sudo[4052]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:17 volumio go-librespot[4054]: time="2025-12-26T14:50:17+01:00" level=fatal msg="failed loading config" error="failed to unmarshal configuration: 2 error(s) decoding:\n\n* cannot parse 'audio_buffer_time' as int: strconv.ParseInt: parsing \"${audio_buffer_time}\": invalid syntax\n* cannot parse 'audio_period_count' as int: strconv.ParseInt: parsing \"${audio_period_count}\": invalid syntax"
Dec 26 14:50:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 26 14:50:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 26 14:50:17 volumio volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 26 14:50:17 volumio volumio[1126]: SPOTIFY: BQDlw1snRVgDDmsBITcQOg7_QhXNNtHc25hzx0Vey0Egi8MpEYABynoV_-adrmB0vIRtz2IoGNxDdD7Fw7wLrqMqMe6ANpprg2FaDPjFULbYFshJ4drNBa4UXyIenutzXFoyvpocPEugORBqre0Fy-CGct_9naGMGgxPQahwyykfWWszJmvgeRllIRXS1K8UoxrTnGDEuaOzLtpT8qd81xacGzgo2Zl_WM14hZobc-I_mJrsUuJv52MMcyeni1nFwOWlPjMJoHoFAU1XU1vw5fEW2nuIJHBUGpUya3c
Dec 26 14:50:17 volumio volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 26 14:50:17 volumio volumio[1126]: info: New Spotify access token = BQDlw1snRVgDDmsBITcQOg7_QhXNNtHc25hzx0Vey0Egi8MpEYABynoV_-adrmB0vIRtz2IoGNxDdD7Fw7wLrqMqMe6ANpprg2FaDPjFULbYFshJ4drNBa4UXyIenutzXFoyvpocPEugORBqre0Fy-CGct_9naGMGgxPQahwyykfWWszJmvgeRllIRXS1K8UoxrTnGDEuaOzLtpT8qd81xacGzgo2Zl_WM14hZobc-I_mJrsUuJv52MMcyeni1nFwOWlPjMJoHoFAU1XU1vw5fEW2nuIJHBUGpUya3c
Dec 26 14:50:17 volumio volumio[1126]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 26 14:50:17 volumio volumio[1126]: SPOTIFY: User informations: {"country":"DE","display_name":"steffen-9-de","email":"steffenzierold@yahoo.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/steffen-9-de"},"followers":{"href":null,"total":4},"href":"https://api.spotify.com/v1/users/steffen-9-de","id":"steffen-9-de","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee855c9381c84863ade44609747f","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b825c9381c84863ade44609747f","width":64}],"product":"premium","type":"user","uri":"spotify:user:steffen-9-de"}
Dec 26 14:50:17 volumio volumio[1126]: info: Spotify Successfully logged in
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 26 14:50:17 volumio volumio[1126]: info: [1766757017860] CoreMusicLibrary::Adding element Spotify
Dec 26 14:50:17 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 26 14:50:17 volumio volumio[1126]: Cannot find translation for source TIDAL
Dec 26 14:50:17 volumio volumio[1126]: Cannot find translation for source Spotify
Dec 26 14:50:19 volumio volumio[1126]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify
Dec 26 14:50:19 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 26 14:50:19 volumio volumio[1126]: Cannot find translation for source TIDAL
Dec 26 14:50:19 volumio volumio[1126]: info: Disabling plugin spop
Dec 26 14:50:19 volumio volumio[1126]: info: Done.
Dec 26 14:50:19 volumio sudo[4063]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service
Dec 26 14:50:19 volumio sudo[4063]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:19 volumio systemd[1]: Stopped go-librespot Daemon.
Dec 26 14:50:19 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:19 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:19 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:19 volumio sudo[4063]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:20 volumio volumio[1126]: info: go-librespot daemon successfully initialized
Dec 26 14:50:21 volumio volumio[1126]: info: Enabling plugin spop
Dec 26 14:50:21 volumio volumio[1126]: info: Loading plugin "spop"...
Dec 26 14:50:21 volumio volumio[1126]: info: PLUGIN START: spop
Dec 26 14:50:21 volumio volumio[1126]: info: Creating Spotify config file
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:21 volumio volumio[1126]: info: Done.
Dec 26 14:50:21 volumio volumio[1126]: info: No need to fix Spotify hosts
Dec 26 14:50:21 volumio volumio[1126]: info: Spotify config file written
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:21 volumio sudo[4066]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Dec 26 14:50:21 volumio sudo[4066]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:21 volumio systemd[1]: Started go-librespot Daemon.
Dec 26 14:50:21 volumio go-librespot[4068]: go-librespot daemon starting...
Dec 26 14:50:21 volumio sudo[4066]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:21 volumio go-librespot[4068]: time="2025-12-26T14:50:21+01:00" level=fatal msg="failed loading config" error="failed to unmarshal configuration: 2 error(s) decoding:\n\n* cannot parse 'audio_buffer_time' as int: strconv.ParseInt: parsing \"${audio_buffer_time}\": invalid syntax\n* cannot parse 'audio_period_count' as int: strconv.ParseInt: parsing \"${audio_period_count}\": invalid syntax"
Dec 26 14:50:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 26 14:50:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 26 14:50:21 volumio volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 26 14:50:21 volumio volumio[1126]: SPOTIFY: BQAuATslLUhM6YoDd-RifmFoSxZ372edHB7HIo627kOydAqLj--5q0K_uW9DV4Tz4C8ax4ZT2klyPkbXMZRZLKcfCPbt81VTN1sA7em7TA-8SqyrD__cDMfdJv59ypbffW2vN0nVaA_fAFMiVzlMdfm0ohsaGCEATMXmfbA2CiVN0vJdFGhp7tMogCU3hMfjJ9wZSLUvPMjFZZi0MgQyjZ7_nqNurvY8stlC1UmTiM9ryfCS_T7Tl0cnV24qIzEiS25O_cJuhTW_-qllAJ0tkULJ_wcnfrmMqoXNDJk
Dec 26 14:50:21 volumio volumio[1126]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Dec 26 14:50:21 volumio volumio[1126]: info: New Spotify access token = BQAuATslLUhM6YoDd-RifmFoSxZ372edHB7HIo627kOydAqLj--5q0K_uW9DV4Tz4C8ax4ZT2klyPkbXMZRZLKcfCPbt81VTN1sA7em7TA-8SqyrD__cDMfdJv59ypbffW2vN0nVaA_fAFMiVzlMdfm0ohsaGCEATMXmfbA2CiVN0vJdFGhp7tMogCU3hMfjJ9wZSLUvPMjFZZi0MgQyjZ7_nqNurvY8stlC1UmTiM9ryfCS_T7Tl0cnV24qIzEiS25O_cJuhTW_-qllAJ0tkULJ_wcnfrmMqoXNDJk
Dec 26 14:50:21 volumio volumio[1126]: info: Spotify credentials grant success - running version from March 24, 2019
Dec 26 14:50:21 volumio volumio[1126]: SPOTIFY: User informations: {"country":"DE","display_name":"steffen-9-de","email":"steffenzierold@yahoo.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/steffen-9-de"},"followers":{"href":null,"total":4},"href":"https://api.spotify.com/v1/users/steffen-9-de","id":"steffen-9-de","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee855c9381c84863ade44609747f","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b825c9381c84863ade44609747f","width":64}],"product":"premium","type":"user","uri":"spotify:user:steffen-9-de"}
Dec 26 14:50:21 volumio volumio[1126]: info: Spotify Successfully logged in
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Dec 26 14:50:21 volumio volumio[1126]: info: [1766757021728] CoreMusicLibrary::Adding element Spotify
Dec 26 14:50:21 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 26 14:50:21 volumio volumio[1126]: Cannot find translation for source TIDAL
Dec 26 14:50:21 volumio volumio[1126]: Cannot find translation for source Spotify
Dec 26 14:50:23 volumio volumio[1126]: info: Disabling plugin Systeminfo
Dec 26 14:50:23 volumio volumio[1126]: info: Done.
Dec 26 14:50:23 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:23 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:23 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:23 volumio volumio[1126]: info: Initializing connection to go-librespot Websocket
Dec 26 14:50:23 volumio volumio[1126]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 26 14:50:24 volumio volumio[1126]: info: Enabling plugin Systeminfo
Dec 26 14:50:24 volumio volumio[1126]: info: Loading plugin "Systeminfo"...
Dec 26 14:50:24 volumio volumio[1126]: info: PLUGIN START: Systeminfo
Dec 26 14:50:24 volumio volumio[1126]: info: Done.
Dec 26 14:50:24 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:24 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:24 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:24 volumio volumio[1126]: info: go-librespot daemon successfully initialized
Dec 26 14:50:24 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 26 14:50:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Dec 26 14:50:24 volumio systemd[1]: Stopped go-librespot Daemon.
Dec 26 14:50:24 volumio systemd[1]: Started go-librespot Daemon.
Dec 26 14:50:24 volumio go-librespot[4075]: go-librespot daemon starting...
Dec 26 14:50:24 volumio go-librespot[4075]: time="2025-12-26T14:50:24+01:00" level=fatal msg="failed loading config" error="failed to unmarshal configuration: 2 error(s) decoding:\n\n* cannot parse 'audio_buffer_time' as int: strconv.ParseInt: parsing \"${audio_buffer_time}\": invalid syntax\n* cannot parse 'audio_period_count' as int: strconv.ParseInt: parsing \"${audio_period_count}\": invalid syntax"
Dec 26 14:50:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 26 14:50:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 26 14:50:26 volumio volumio[1126]: info: Enabling plugin fusiondsp
Dec 26 14:50:26 volumio volumio[1126]: info: Loading plugin "fusiondsp"...
Dec 26 14:50:26 volumio volumio[1126]: info: Applying required configuration parameters for plugin fusiondsp
Dec 26 14:50:26 volumio volumio[1126]: info: Preparing to generate the ALSA configuration file
Dec 26 14:50:26 volumio volumio[1126]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Dec 26 14:50:26 volumio volumio[1126]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Dec 26 14:50:26 volumio volumio[1126]: info: Reading ALSA contributions from plugins.
Dec 26 14:50:26 volumio volumio[1126]: info: Asound.conf file written
Dec 26 14:50:26 volumio sudo[4098]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Dec 26 14:50:26 volumio sudo[4098]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio sudo[4098]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio volumio[1126]: info: Output device has changed, restarting MPD
Dec 26 14:50:26 volumio sudo[4103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 26 14:50:26 volumio sudo[4103]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio sudo[4103]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio vtcs[3982]: [2025-12-26 14:50:26.374] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected
Dec 26 14:50:26 volumio vtcs[3982]: [2025-12-26 14:50:26.374] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE
Dec 26 14:50:26 volumio sudo[4106]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 26 14:50:26 volumio sudo[4106]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio volumio[1126]: info: PLUGIN START: fusiondsp
Dec 26 14:50:26 volumio volumio[1126]: info: Loading i18n strings for locale de
Dec 26 14:50:26 volumio sudo[4109]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:50:26 volumio sudo[4109]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio systemd[1]: Stopping Music Player Daemon...
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - mixtype--------------------- Software
Dec 26 14:50:26 volumio volumio[1126]: info: Preparing to generate the ALSA configuration file
Dec 26 14:50:26 volumio systemd[1]: Stopping Volumio Tidal Connect Service...
Dec 26 14:50:26 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM
Dec 26 14:50:26 volumio systemd[1]: vtcs.service: Succeeded.
Dec 26 14:50:26 volumio systemd[1]: Stopped Volumio Tidal Connect Service.
Dec 26 14:50:26 volumio systemd[1]: mpd.service: Succeeded.
Dec 26 14:50:26 volumio systemd[1]: Stopped Music Player Daemon.
Dec 26 14:50:26 volumio volumio[1126]: info: Done.
Dec 26 14:50:26 volumio sudo[4109]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio volumio[1126]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
Dec 26 14:50:26 volumio volumio[1126]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Dec 26 14:50:26 volumio volumio[1126]: info: Reading ALSA contributions from plugins.
Dec 26 14:50:26 volumio volumio[1126]: info: MPD Permissions set
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio sudo[4114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:50:26 volumio sudo[4114]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: Asound.conf file unchanged, so no further update is needed
Dec 26 14:50:26 volumio volumio[1126]: info: Output device has changed, restarting MPD
Dec 26 14:50:26 volumio systemd[1]: Starting Music Player Daemon...
Dec 26 14:50:26 volumio sudo[4121]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Dec 26 14:50:26 volumio sudo[4121]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio sudo[4121]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio sudo[4125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Dec 26 14:50:26 volumio sudo[4125]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio sudo[4114]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM
Dec 26 14:50:26 volumio systemd[1]: mpd.service: Succeeded.
Dec 26 14:50:26 volumio systemd[1]: Stopped Music Player Daemon.
Dec 26 14:50:26 volumio systemd[1]: Starting Music Player Daemon...
Dec 26 14:50:26 volumio sudo[4129]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:50:26 volumio sudo[4129]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio volumio[1126]: info: MPD Permissions set
Dec 26 14:50:26 volumio sudo[4133]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Dec 26 14:50:26 volumio sudo[4133]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio sudo[4129]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:26 volumio sudo[4133]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio sudo[4130]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Dec 26 14:50:26 volumio sudo[4130]: pam_unix(sudo:session): session opened for user root by (uid=0)
Dec 26 14:50:26 volumio sudo[4130]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:26 volumio volumio[1126]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - Choose a preset
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - Choose a preset
Dec 26 14:50:26 volumio volumio[1126]: info: Initializing connection to go-librespot Websocket
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - Choose a preset
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json
Dec 26 14:50:26 volumio volumio[1126]: info: FusionDsp - .Bass-FusionDsp.json,.Classic-FusionDsp.json,.Rock-FusionDsp.json,.Soundtrack-FusionDsp.json,.Voice-FusionDsp.json
Dec 26 14:50:26 volumio volumio[1126]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 26 14:50:26 volumio mpd[4142]: Dec 26 14:50 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Dec 26 14:50:26 volumio systemd[1]: Started Music Player Daemon.
Dec 26 14:50:26 volumio sudo[4106]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio sudo[4125]: pam_unix(sudo:session): session closed for user root
Dec 26 14:50:26 volumio volumio[1126]: error: MPD error: The expression evaluated to a falsy value:
Dec 26 14:50:26 volumio volumio[1126]: assert.ok(self.idling)
Dec 26 14:50:26 volumio volumio[1126]: error: The expression evaluated to a falsy value:
Dec 26 14:50:26 volumio volumio[1126]: assert.ok(self.idling)
Dec 26 14:50:26 volumio volumio[1126]: error: updateQueue error: null
Dec 26 14:50:26 volumio kernel: hwmon hwmon2: Undervoltage detected!
Dec 26 14:50:27 volumio volumio[1126]: info: Initializing connection to go-librespot Websocket
Dec 26 14:50:27 volumio volumio[1126]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Dec 26 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart.
Dec 26 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Dec 26 14:50:27 volumio systemd[1]: Stopped go-librespot Daemon.
Dec 26 14:50:27 volumio systemd[1]: Started go-librespot Daemon.
Dec 26 14:50:27 volumio go-librespot[4146]: go-librespot daemon starting...
Dec 26 14:50:27 volumio go-librespot[4146]: time="2025-12-26T14:50:27+01:00" level=fatal msg="failed loading config" error="failed to unmarshal configuration: 2 error(s) decoding:\n\n* cannot parse 'audio_buffer_time' as int: strconv.ParseInt: parsing \"${audio_buffer_time}\": invalid syntax\n* cannot parse 'audio_period_count' as int: strconv.ParseInt: parsing \"${audio_period_count}\": invalid syntax"
Dec 26 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 26 14:50:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 26 14:50:27 volumio volumio[1126]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 26 14:50:27 volumio volumio[1126]: TypeError: Cannot read property 'off' of undefined
Dec 26 14:50:27 volumio volumio[1126]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:107:15)
Dec 26 14:50:27 volumio volumio[1126]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30)
Dec 26 14:50:27 volumio volumio[1126]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8)
Dec 26 14:50:27 volumio volumio[1126]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29)
Dec 26 14:50:27 volumio volumio[1126]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1412:47)
Dec 26 14:50:27 volumio volumio[1126]: at Socket.emit (events.js:315:20)
Dec 26 14:50:27 volumio volumio[1126]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Dec 26 14:50:27 volumio volumio[1126]: at processTicksAndRejections (internal/process/task_queues.js:75:11)
Dec 26 14:50:27 volumio volumio[1126]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 26 14:50:28 volumio sudo[4162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-26 14:49
Dec 26 14:50:28 volumio sudo[4162]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET"
VOLUMIO_VERSION="3.886"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"