-- Logs begin at Tue 2023-03-28 01:54:07 CST, end at Thu 2025-06-19 10:24:42 CST. -- Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Loading plugin "networkfs"... Jun 19 10:23:00 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/system_controller/networkfs/index.js Jun 19 10:23:00 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Loading plugin "alarm-clock"... Jun 19 10:23:00 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/miscellanea/alarm-clock/index.js Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Loading plugin "airplay_emulation"... Jun 19 10:23:00 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/airplay_emulation/index.js Jun 19 10:23:00 ft1905-febf volumio[6639]: Shairport Sync D-Bus 服务已注册。 Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Starting Shairport Sync Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Loading plugin "last_100"... Jun 19 10:23:00 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/last_100/index.js Jun 19 10:23:00 ft1905-febf volumio[6639]: info: Loading plugin "spop"... Jun 19 10:23:00 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/spop/index.js Jun 19 10:23:01 ft1905-febf volumio[6639]: SPOTIFY: resetSpotifyState Jun 19 10:23:01 ft1905-febf volumio[6639]: info: Loading plugin "webradio"... Jun 19 10:23:01 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/webradio/index.js Jun 19 10:23:01 ft1905-febf mpd[6716]: Jun 19 10:23 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 19 10:23:01 ft1905-febf mpd[6716]: Jun 19 10:23 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 19 10:23:01 ft1905-febf mpd[6716]: Jun 19 10:23 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 19 10:23:01 ft1905-febf systemd[1]: Started Music Player Daemon. Jun 19 10:23:01 ft1905-febf sudo[6703]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Loading plugin "yandex"... Jun 19 10:23:03 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/yandex/index.js Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Yandex plugin started Jun 19 10:23:03 ft1905-febf volumio[6639]: error: ATTENTION!!!: Plugin yandex does not return adequate promise from onVolumioStart: please update! Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Loading plugin "i2s_dacs"... Jun 19 10:23:03 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/system_controller/i2s_dacs/index.js Jun 19 10:23:03 ft1905-febf volumio[6639]: info: I2S DAC not set, start Auto-detection Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Loading plugin "volumiodiscovery"... Jun 19 10:23:03 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/system_controller/volumiodiscovery/index.js Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** For more information see Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 19 10:23:03 ft1905-febf volumio[6639]: *** WARNING *** For more information see Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** For more information see Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 19 10:23:03 ft1905-febf node[6639]: *** WARNING *** For more information see Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Discovery: Started advertising with name: FT1905-febf Jun 19 10:23:03 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Loading plugin "outputs"... Jun 19 10:23:03 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/audio_interface/outputs/index.js Jun 19 10:23:03 ft1905-febf volumio[6639]: info: Loading plugin "albumart"... Jun 19 10:23:03 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/miscellanea/albumart/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Plugin example_plugin is not enabled Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "inputs"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/inputs/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "pandora"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/pandora/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Applying required configuration parameters for plugin pandora Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "podcast"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/podcast/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: info: ControllerPodcast::constructor Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "qobuz"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/qobuz/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: error: ATTENTION!!!: Plugin qobuz does not return adequate promise from onVolumioStart: please update! Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "tidal"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/music_service/tidal/index.js Jun 19 10:23:04 ft1905-febf volumio[6639]: info: [1750299784944] ControllerTidalPlugin::constructor Jun 19 10:23:04 ft1905-febf volumio[6639]: info: [1750299784947] ControllerTidalPlugin::onVolumioStart Jun 19 10:23:04 ft1905-febf volumio[6639]: info: Loading plugin "updater_comm"... Jun 19 10:23:04 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/system_controller/updater_comm/index.js Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Plugin mpdemulation is not enabled Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Loading plugin "rest_api"... Jun 19 10:23:05 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/user_interface/rest_api/index.js Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Loading plugin "websocket"... Jun 19 10:23:05 ft1905-febf volumio[6639]: [ require ] /volumio/app/plugins/user_interface/websocket/index.js Jun 19 10:23:05 ft1905-febf volumio[6639]: info: ___________ START PLUGINS ___________ Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785191] CoreMusicLibrary::Adding element Media Servers Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: SSDP Client initialized. Jun 19 10:23:05 ft1905-febf volumio[6639]: Starting initial SSDP search... Jun 19 10:23:05 ft1905-febf volumio[6639]: Discovering on interface: lo Jun 19 10:23:05 ft1905-febf volumio[6639]: Discovering on interface: eth0 Jun 19 10:23:05 ft1905-febf volumio[6639]: Discovering on interface: wlan0 Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785333] CoreMusicLibrary::Adding element Last_100 Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Creating Spotify config file Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785480] CoreMusicLibrary::Adding element Webradio Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Yandex plugin started Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785504] ControllerYandexPlugin::addToBrowseSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785505] CoreMusicLibrary::Adding element Yandex Music Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: error: Plugin yandex does not return adequate promise from onStart: please update! Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785522] CoreMusicLibrary::Adding element Pandora Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785529] ControllerPandora::initializeMQTT Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785530] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785545] CoreMusicLibrary::Adding element Podcast Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785552] CoreMusicLibrary::Adding element Qobuz Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785566] ControllerTidalPlugin::onStart Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785574] ControllerTidalPlugin::addToBrowseSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:05 ft1905-febf volumio[6639]: info: [1750299785576] CoreMusicLibrary::Adding element Tidal Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: Loading i18n strings for locale zh Jun 19 10:23:05 ft1905-febf volumio[6639]: Updating browse sources language Jun 19 10:23:05 ft1905-febf volumio[6639]: Cannot find translation for sourceMedia Servers Jun 19 10:23:05 ft1905-febf volumio[6639]: Cannot find translation for sourceYandex Music Jun 19 10:23:05 ft1905-febf volumio[6639]: Cannot find translation for sourcePodcast Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::initPlayerControls Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 19 10:23:05 ft1905-febf volumio[6639]: info: BOOT COMPLETED Jun 19 10:23:05 ft1905-febf volumio[6639]: [Metrics] CommandRouter: 9s 588.08ms Jun 19 10:23:05 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 19 10:23:05 ft1905-febf kernel: sunxi-spdif 2036000.spdif: active: 1 Jun 19 10:23:09 ft1905-febf socketio[2756]: [2025-06-19 10:23:09] [connect] Successful connection Jun 19 10:23:11 ft1905-febf volumio[6639]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::Close All Modals sent Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::Close All Modals sent Jun 19 10:23:11 ft1905-febf volumio[6639]: Express server listening on port 3000 Jun 19 10:23:11 ft1905-febf volumio[6639]: [Metrics] WebUI: 15s 600.02ms Jun 19 10:23:11 ft1905-febf volumio[6639]: (node:6639) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Jun 19 10:23:11 ft1905-febf volumio[6639]: info: [1750299791322] ControllerPandora::validateAndSetAccountOptions Jun 19 10:23:11 ft1905-febf volumio[6639]: error: [1750299791325] [Pandora] validateAndSetAccountOptions: Need email address and password. See plugin settings. Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreStateMachine::resetVolumioState Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreStateMachine::getcurrentVolume Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioRetrievevolume Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 19 10:23:11 ft1905-febf sudo[6890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 19 10:23:11 ft1905-febf volumio[6639]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jun 19 10:23:11 ft1905-febf sudo[6893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 19 10:23:11 ft1905-febf sudo[6890]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 19 10:23:11 ft1905-febf sudo[6890]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:11 ft1905-febf sudo[6893]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 19 10:23:11 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:11 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:11 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:11 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:11 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:11 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:11 ft1905-febf volumio[6639]: USN: Jun 19 10:23:11 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:11 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:11 ft1905-febf sudo[6893]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:11 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:11 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:11 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:11 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:11 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:11 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:11 ft1905-febf volumio[6639]: USN: Jun 19 10:23:11 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:11 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:11 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:11 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:11 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:11 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:11 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:11 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:11 ft1905-febf volumio[6639]: USN: Jun 19 10:23:11 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:11 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:11 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:11 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:11 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:11 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:11 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:11 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:11 ft1905-febf volumio[6639]: USN: Jun 19 10:23:11 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:11 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:11 ft1905-febf volumio[6639]: info: this.stateMachine.currentVolume: null, vol: 0 Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreStateMachine::pushState Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreStateMachine::updateTrackBlock Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CorePlayQueue::getTrackBlock Jun 19 10:23:11 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioRetrievevolume Jun 19 10:23:12 ft1905-febf volumio[6639]: info: MPD Permissions set Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 19 10:23:12 ft1905-febf volumio[6639]: Device response: { SERVER: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:12 ft1905-febf volumio[6639]: LOCATION: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:12 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:12 ft1905-febf volumio[6639]: USN: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:12 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:12 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:12 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:12 ft1905-febf volumio[6639]: Device response: { SERVER: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:12 ft1905-febf volumio[6639]: LOCATION: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:12 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:12 ft1905-febf volumio[6639]: USN: Jun 19 10:23:12 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:12 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:12 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:12 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:12 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:12 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:12 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf volumio[6916]: Forking 1 albumart workers Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf socketio[2756]: [2025-06-19 10:23:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1750299789 101 Jun 19 10:23:13 ft1905-febf socketio[2756]: sio connected Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf volumio[6639]: info: Cannot read I2C interface or I2C interface not presentError: Command failed: /usr/bin/sudo /usr/sbin/i2cdetect -y 1 Jun 19 10:23:13 ft1905-febf volumio[6639]: sudo: /usr/sbin/i2cdetect: command not found Jun 19 10:23:13 ft1905-febf volumio[6639]: info: Spotify config file written Jun 19 10:23:13 ft1905-febf volumio[6639]: Device response: { SERVER: Jun 19 10:23:13 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:13 ft1905-febf volumio[6639]: LOCATION: Jun 19 10:23:13 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:13 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:13 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:13 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:13 ft1905-febf volumio[6639]: USN: Jun 19 10:23:13 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:13 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:13 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:13 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800' } Jun 19 10:23:13 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf sudo[6963]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart go-librespot-daemon.service Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf sudo[6963]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf systemd[1]: Stopping go-librespot Daemon... Jun 19 10:23:13 ft1905-febf systemd[1]: go-librespot-daemon.service: Succeeded. Jun 19 10:23:13 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 19 10:23:13 ft1905-febf sudo[6963]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf go-librespot[6972]: go-librespot daemon starting... Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf go-librespot[6977]: time="2025-06-19T10:23:13+08:00" level=info msg="running go-librespot 0.2.0" Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:13 ft1905-febf go-librespot[6977]: time="2025-06-19T10:23:13+08:00" level=debug msg="app state loaded" Jun 19 10:23:13 ft1905-febf go-librespot[6977]: time="2025-06-19T10:23:13+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 19 10:23:13 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:13 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6639]: sendCommand: Command { name: 'playlistinfo', args: [] } Jun 19 10:23:14 ft1905-febf volumio[6639]: sendCommand: Command { name: 'lsinfo "USB"', args: [] } Jun 19 10:23:14 ft1905-febf volumio[6639]: sendCommand: Command { name: 'search album ""', args: [] } Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:14 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:14 ft1905-febf volumio[6950]: Starting albumart workers Jun 19 10:23:14 ft1905-febf volumio[6639]: info: MPD running with PID6716 Jun 19 10:23:14 ft1905-febf volumio[6639]: ,establishing connection Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:14 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 19 10:23:15 ft1905-febf volumio[6639]: info: No need to fix Spotify hosts Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:15 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:15 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:15 ft1905-febf volumio[6639]: error: updateQueue error: null Jun 19 10:23:15 ft1905-febf volumio[6639]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 19 10:23:15 ft1905-febf volumio[6639]: Device response: { SERVER: Jun 19 10:23:15 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:15 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:15 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:15 ft1905-febf volumio[6639]: USN: Jun 19 10:23:15 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:15 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:15 ft1905-febf volumio[6639]: LOCATION: Jun 19 10:23:15 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:15 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:11 GMT', Jun 19 10:23:15 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:15 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:15 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreStateMachine::setRepeat null single undefined Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreStateMachine::pushState Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreStateMachine::setRandom false Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreStateMachine::pushState Jun 19 10:23:15 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 19 10:23:15 ft1905-febf volumio[6639]: sendCommand: Command { name: 'playlistinfo', args: [] } Jun 19 10:23:15 ft1905-febf volumio[6639]: error: updateQueue error: null Jun 19 10:23:15 ft1905-febf volumio[6639]: info: Starting Shairport Sync Jun 19 10:23:15 ft1905-febf sudo[7020]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 19 10:23:15 ft1905-febf volumio[6639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 19 10:23:15 ft1905-febf volumio[6639]: SPOTIFY: BQA6_k6eGTPDupXD9-g4G0aUZYgap4nCYpqkRHkc7_vOTKirnZdlYmp-vdyeqNsoPgEryvPU9Xn52EMydRgwzGlojz_ghmLCfLjOaXR_aJwDtFcZCcA7-5YAN7IrlFF3C1GiuXu2IsXbHizK87IEhoCKzFFnzE4aarhKQfJQq14fcay_vHxq7EwLqiiRwDmR6AxCG0is_iBkUMdwcbNwUueaW-4dcSdaO9hXAmRI_aNCbe7NVgQ53kQEihKkBigqR4S5U4kcJu4zaKVOvmfQEPBHo27ylIfl-WVEJhzgseOvnHxkRew Jun 19 10:23:15 ft1905-febf volumio[6639]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jun 19 10:23:15 ft1905-febf volumio[6639]: info: New Spotify access token = BQA6_k6eGTPDupXD9-g4G0aUZYgap4nCYpqkRHkc7_vOTKirnZdlYmp-vdyeqNsoPgEryvPU9Xn52EMydRgwzGlojz_ghmLCfLjOaXR_aJwDtFcZCcA7-5YAN7IrlFF3C1GiuXu2IsXbHizK87IEhoCKzFFnzE4aarhKQfJQq14fcay_vHxq7EwLqiiRwDmR6AxCG0is_iBkUMdwcbNwUueaW-4dcSdaO9hXAmRI_aNCbe7NVgQ53kQEihKkBigqR4S5U4kcJu4zaKVOvmfQEPBHo27ylIfl-WVEJhzgseOvnHxkRew Jun 19 10:23:15 ft1905-febf volumio[6639]: info: Spotify credentials grant success - running version from March 24, 2019 Jun 19 10:23:15 ft1905-febf sudo[7020]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 19 10:23:15 ft1905-febf sudo[7024]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioGetVisibleSources Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:16 ft1905-febf sudo[7024]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 19 10:23:16 ft1905-febf volumio[6639]: info: Listing playlists Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioGetQueue Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CoreStateMachine::getQueue Jun 19 10:23:16 ft1905-febf volumio[6639]: info: CorePlayQueue::getQueue Jun 19 10:23:16 ft1905-febf systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 19 10:23:16 ft1905-febf systemd[1]: shairport-sync.service: Succeeded. Jun 19 10:23:16 ft1905-febf systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 19 10:23:16 ft1905-febf systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 19 10:23:16 ft1905-febf sudo[7020]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:16 ft1905-febf sudo[7024]: pam_unix(sudo:session): session closed for user root Jun 19 10:23:16 ft1905-febf volumio[6639]: Discovery: adding 28bc41e0-af37-44db-b28c-6c26e99ff0b2 Jun 19 10:23:16 ft1905-febf volumio[6639]: info: mDNS: Found device FT1905-febf Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: info: Upmpdcli Daemon Started Jun 19 10:23:16 ft1905-febf volumio[6639]: info: Shairport-Sync Started Jun 19 10:23:16 ft1905-febf volumio[6639]: Error adding Membership: Error: addMembership EINVAL Jun 19 10:23:16 ft1905-febf volumio[6639]: Discovery: this is already registered, 28bc41e0-af37-44db-b28c-6c26e99ff0b2 Jun 19 10:23:16 ft1905-febf volumio[6639]: info: mDNS: Found device FT1905-febf Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: Discovery: this is already registered, 28bc41e0-af37-44db-b28c-6c26e99ff0b2 Jun 19 10:23:16 ft1905-febf volumio[6639]: info: mDNS: Found device FT1905-febf Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:16 ft1905-febf volumio[6639]: error: Could not retrieve plugin audio_interface multiroom Jun 19 10:23:18 ft1905-febf volumio[6639]: SPOTIFY: User informations: {"country":"NG","display_name":"surui2","email":"surui2@126.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31dobbykadpjqbg53ytmzna3bo7u"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31dobbykadpjqbg53ytmzna3bo7u","id":"31dobbykadpjqbg53ytmzna3bo7u","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee850b8b915c295ca470ca2440a0","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b820b8b915c295ca470ca2440a0","width":64}],"product":"premium","type":"user","uri":"spotify:user:31dobbykadpjqbg53ytmzna3bo7u"} Jun 19 10:23:18 ft1905-febf volumio[6639]: info: Spotify Successfully logged in Jun 19 10:23:18 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 19 10:23:18 ft1905-febf volumio[6639]: info: [1750299798508] CoreMusicLibrary::Adding element Spotify Jun 19 10:23:18 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 19 10:23:18 ft1905-febf volumio[6639]: info: go-librespot daemon successfully initialized Jun 19 10:23:21 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:21 ft1905-febf go-librespot[6977]: time="2025-06-19T10:23:21+08:00" level=debug msg="new websocket client" Jun 19 10:23:21 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket established Jun 19 10:23:24 ft1905-febf volumio[6639]: SPOTIFY: resetSpotifyState Jun 19 10:23:24 ft1905-febf volumio[6639]: info: Getting Spotify volume Jun 19 10:23:24 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:24 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:28 ft1905-febf go-librespot[6977]: time="2025-06-19T10:23:28+08:00" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": unexpected EOF" Jun 19 10:23:28 ft1905-febf systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 19 10:23:28 ft1905-febf systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 19 10:23:28 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket closed Jun 19 10:23:28 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 19 10:23:28 ft1905-febf volumio[6639]: at createHangUpError (_http_client.js:332:15) Jun 19 10:23:28 ft1905-febf volumio[6639]: at Socket.socketOnEnd (_http_client.js:435:23) Jun 19 10:23:28 ft1905-febf volumio[6639]: at Socket.emit (events.js:203:15) Jun 19 10:23:28 ft1905-febf volumio[6639]: at endReadableNT (_stream_readable.js:1145:12) Jun 19 10:23:28 ft1905-febf volumio[6639]: at process._tickCallback (internal/process/next_tick.js:63:19) Jun 19 10:23:28 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1) Jun 19 10:23:28 ft1905-febf volumio[6639]: (node:6639) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Jun 19 10:23:29 ft1905-febf volumio[6639]: error: An error occurred while listing Spotify categories WebapiError: Client network socket disconnected before secure TLS connection was established Jun 19 10:23:29 ft1905-febf volumio[6639]: info: An error occurred while getting Spotify ROOT Discover Folders: Jun 19 10:23:31 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:31 ft1905-febf volumio[6639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 19 10:23:31 ft1905-febf systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jun 19 10:23:31 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 19 10:23:31 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 19 10:23:31 ft1905-febf go-librespot[7071]: go-librespot daemon starting... Jun 19 10:23:31 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:31+08:00" level=info msg="running go-librespot 0.2.0" Jun 19 10:23:31 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:31+08:00" level=debug msg="app state loaded" Jun 19 10:23:31 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:31+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 19 10:23:34 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:34+08:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 19 10:23:34 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:34+08:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 19 10:23:34 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:34+08:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 19 10:23:34 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:34+08:00" level=info msg="zeroconf server listening on port 46457" Jun 19 10:23:34 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:34 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:34+08:00" level=debug msg="new websocket client" Jun 19 10:23:34 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket established Jun 19 10:23:35 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:35+08:00" level=debug msg="obtained new client token: AADJqW+2wIiDCEdKOBOUVjnz3jdhN2WSIZ+wWy0p3maZPm6QBhNEtNAeqFKpxyP7xyMhjJK0RS2UE0JnVxOx3f4BrdseU2csgrnW6HoEEJzYLiLTEtBpQZfpB6via4ksfeNKWUi0+Vz1Be9cLk42myW7P1GjGYZcTkmHqFK2dV5H6v6tkKbb9Gql97EEl3aN8l/2vn3hP6u6ne9xNbvXeB8PYW+udWoATwa0pgsBnqJmmxALXYoaHXXP" Jun 19 10:23:35 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:35+08:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 19 10:23:35 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 19 10:23:35 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 19 10:23:37 ft1905-febf volumio[6639]: SPOTIFY: resetSpotifyState Jun 19 10:23:37 ft1905-febf volumio[6639]: info: Getting Spotify volume Jun 19 10:23:37 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:37 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:40 ft1905-febf go-librespot[7072]: time="2025-06-19T10:23:40+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.2.128:33410->198.18.3.68:4070: read: connection reset by peer" Jun 19 10:23:40 ft1905-febf systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 19 10:23:40 ft1905-febf systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 19 10:23:40 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 19 10:23:40 ft1905-febf volumio[6639]: at createHangUpError (_http_client.js:332:15) Jun 19 10:23:40 ft1905-febf volumio[6639]: at Socket.socketOnEnd (_http_client.js:435:23) Jun 19 10:23:40 ft1905-febf volumio[6639]: at Socket.emit (events.js:203:15) Jun 19 10:23:40 ft1905-febf volumio[6639]: at endReadableNT (_stream_readable.js:1145:12) Jun 19 10:23:40 ft1905-febf volumio[6639]: at process._tickCallback (internal/process/next_tick.js:63:19) Jun 19 10:23:40 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 2) Jun 19 10:23:40 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket closed Jun 19 10:23:43 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:43 ft1905-febf volumio[6639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 19 10:23:43 ft1905-febf systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jun 19 10:23:43 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 19 10:23:43 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 19 10:23:43 ft1905-febf go-librespot[7094]: go-librespot daemon starting... Jun 19 10:23:43 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:43+08:00" level=info msg="running go-librespot 0.2.0" Jun 19 10:23:43 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:43+08:00" level=debug msg="app state loaded" Jun 19 10:23:43 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:43+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 19 10:23:45 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:45+08:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 19 10:23:45 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:45+08:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 19 10:23:45 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:45+08:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 19 10:23:45 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:45+08:00" level=info msg="zeroconf server listening on port 45549" Jun 19 10:23:46 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:46 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:46+08:00" level=debug msg="new websocket client" Jun 19 10:23:46 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket established Jun 19 10:23:47 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:47+08:00" level=debug msg="obtained new client token: AAAvQkhsG2dZis1EAMVqf84Y2bpADQhh5qR6hmi75P7pDReANt/5hoXkYa/PVVLNx6RJ/nM6GCOGb+ASTKvSbVIaghJNwBXlS0jP3x96ISNg5GggyMVCGpVde41axdqGT8WZ2p6AXc/mKUx5lHMakd574jKOMkZcYRuOHvF/dHYFJ/BkjcUq4UZlJRftHH3dwuak/jPhrFl9RjWU+jO1hELeMojeggVpSzLCNEYxBQdZpGHfulAt9poN5nM=" Jun 19 10:23:47 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:47+08:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 19 10:23:49 ft1905-febf volumio[6639]: SPOTIFY: resetSpotifyState Jun 19 10:23:49 ft1905-febf volumio[6639]: info: Getting Spotify volume Jun 19 10:23:49 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:23:49 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:23:53 ft1905-febf go-librespot[7095]: time="2025-06-19T10:23:53+08:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jun 19 10:23:53 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Error: socket hang up Jun 19 10:23:53 ft1905-febf volumio[6639]: at createHangUpError (_http_client.js:332:15) Jun 19 10:23:53 ft1905-febf volumio[6639]: at Socket.socketOnEnd (_http_client.js:435:23) Jun 19 10:23:53 ft1905-febf volumio[6639]: at Socket.emit (events.js:203:15) Jun 19 10:23:53 ft1905-febf volumio[6639]: at endReadableNT (_stream_readable.js:1145:12) Jun 19 10:23:53 ft1905-febf volumio[6639]: at process._tickCallback (internal/process/next_tick.js:63:19) Jun 19 10:23:53 ft1905-febf volumio[6639]: (node:6639) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 3) Jun 19 10:23:53 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket closed Jun 19 10:23:53 ft1905-febf systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jun 19 10:23:53 ft1905-febf systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jun 19 10:23:55 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:55 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:55 GMT', Jun 19 10:23:55 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:55 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:55 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:55 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:55 ft1905-febf volumio[6639]: USN: Jun 19 10:23:55 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:55 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:55 ft1905-febf volumio[6639]: Device response: { 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:55 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:55 GMT', Jun 19 10:23:55 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:55 ft1905-febf volumio[6639]: LOCATION: 'http://192.168.2.1:4044/dev.xml', Jun 19 10:23:55 ft1905-febf volumio[6639]: SERVER: 'eXtensible UPnP agent', Jun 19 10:23:55 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:55 ft1905-febf volumio[6639]: USN: Jun 19 10:23:55 ft1905-febf volumio[6639]: 'uuid:60bd2fb3-dabe-cb14-c766-0e319b54c29a::urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:55 ft1905-febf volumio[6639]: Device IP: 192.168.2.1 Jun 19 10:23:56 ft1905-febf volumio[6639]: Device response: { LOCATION: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:56 ft1905-febf volumio[6639]: SERVER: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:56 ft1905-febf volumio[6639]: USN: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:56 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:56 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:55 GMT', Jun 19 10:23:56 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800' } Jun 19 10:23:56 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:56 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:56 ft1905-febf volumio[6639]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jun 19 10:23:56 ft1905-febf volumio[6639]: Device response: { LOCATION: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'http://192.168.2.143:9365/MediaServer/DeviceDescription.xml', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'CONFIGID.UPNP.ORG': '0', Jun 19 10:23:56 ft1905-febf volumio[6639]: SERVER: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'Mac-OS-X/13.7.4 UPnP/1.1 DLNADOC/1.5 Cyaneous-FireStream/2.0', Jun 19 10:23:56 ft1905-febf volumio[6639]: USN: Jun 19 10:23:56 ft1905-febf volumio[6639]: 'uuid:3fdad695-204c-65d4-4e83-c8f2cf400401::urn:schemas-upnp-org:device:MediaServer:1', Jun 19 10:23:56 ft1905-febf volumio[6639]: EXT: '', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'BOOTID.UPNP.ORG': '1750147183', Jun 19 10:23:56 ft1905-febf volumio[6639]: DATE: 'Thu, 19 Jun 2025 02:23:55 GMT', Jun 19 10:23:56 ft1905-febf volumio[6639]: 'CACHE-CONTROL': 'max-age=1800', Jun 19 10:23:56 ft1905-febf volumio[6639]: ST: 'urn:schemas-upnp-org:device:MediaServer:1' } Jun 19 10:23:56 ft1905-febf volumio[6639]: Device IP: 192.168.2.143 Jun 19 10:23:57 ft1905-febf systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jun 19 10:23:57 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 19 10:23:57 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 19 10:23:57 ft1905-febf go-librespot[7114]: go-librespot daemon starting... Jun 19 10:23:57 ft1905-febf go-librespot[7115]: time="2025-06-19T10:23:57+08:00" level=info msg="running go-librespot 0.2.0" Jun 19 10:23:57 ft1905-febf go-librespot[7115]: time="2025-06-19T10:23:57+08:00" level=debug msg="app state loaded" Jun 19 10:23:57 ft1905-febf go-librespot[7115]: time="2025-06-19T10:23:57+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 19 10:23:59 ft1905-febf volumio[6639]: info: Initializing connection to go-librespot Websocket Jun 19 10:23:59 ft1905-febf go-librespot[7115]: time="2025-06-19T10:23:59+08:00" level=debug msg="new websocket client" Jun 19 10:23:59 ft1905-febf volumio[6639]: info: Connection to go-librespot Websocket established Jun 19 10:24:00 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:00+08:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jun 19 10:24:00 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:00+08:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 19 10:24:00 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:00+08:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 19 10:24:00 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:00+08:00" level=info msg="zeroconf server listening on port 37569" Jun 19 10:24:02 ft1905-febf volumio[6639]: SPOTIFY: resetSpotifyState Jun 19 10:24:02 ft1905-febf volumio[6639]: info: Getting Spotify volume Jun 19 10:24:03 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 19 10:24:03 ft1905-febf volumio[6639]: info: [pushCmd] {"index":5,"getInfo":0} Jun 19 10:24:05 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:05+08:00" level=debug msg="obtained new client token: AAAKzswtfRmPItANVE5wjP99Nvdcceqo/YR/SSOvNCx+tEOAWyIegn4itxzbYsUA3X7d11WS+VAJIHWTMIhzMMQFkIFMWPYV8qn4SRKTg2jtKEO57UwYRl5E+yrSqbotorf6wZIU8C83VAUEKlbK/oZtOKuqTGpt5+1B8cq0o1TFb7PUoR0Bkl61RK4C97blzCzJIJzjACGZ1cj51KQmi8DUglJz5z/2Z7QC3eOWuOw162WreCiz/OQnHCg=" Jun 19 10:24:06 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:06+08:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jun 19 10:24:08 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:08+08:00" level=debug msg="completed keyexchange" Jun 19 10:24:08 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:08+08:00" level=debug msg="completed challenge" Jun 19 10:24:08 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:08+08:00" level=info msg="authenticated AP as 31dobbykadpjqbg53ytmzna3bo7u" Jun 19 10:24:15 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:15+08:00" level=info msg="authenticated Login5 as 31dobbykadpjqbg53ytmzna3bo7u" Jun 19 10:24:15 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:15+08:00" level=debug msg="initializing zeroconf session, username: 31dobbykadpjqbg53ytmzna3bo7u" Jun 19 10:24:23 ft1905-febf go-librespot[7115]: time="2025-06-19T10:24:23+08:00" level=error msg="failed connecting to dealer" error="failed to WebSocket dial: failed to send handshake request: Get \"https://gue1-dealer.spotify.com:443/?access_token=BQCe9-y3r-McMU61HPIFOBvyAKmM6Fh1VVig_72VY6nIwdQc6mGCU1yRJ75Nu9KcZiaBcVXkXhTivGO6PbVPmrghdIbkW45KWrkp1HtVwSgC_dqYV5r3Rm7rHFkmMImRxm1AW9NVzf7wb2Snlip5447k4XrAOJ6oeVSNZX9qkj3MQasD4YtAnW5jWwEvvAa-__IqRiWwWmdgHIRg_xkrLsRlHeteddu37PMbYOEFxExR7yi_xVvh5ZtQX3UZcWaRDwN0OCtGUAN8JFRqKTJtgiGkB0eqWZuQDjMhBFuqxkize2Qep-rfCQoc-ERk4I25UmbctAFr77CiFRdP44qYXc__IXum-KI8538QqkR9seU6aMrMlbqbxVA6cPkkoGYFHPYivE0cbChbaPRxy-H5ZQUIK3Bb9a6imCTP2w\": EOF" Jun 19 10:24:33 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: yandex , handleBrowseUri Jun 19 10:24:33 ft1905-febf volumio[6639]: info: [1750299873961] ControllerYandexPlugin::handleBrowseUri Jun 19 10:24:33 ft1905-febf volumio[6639]: info: handleBrowseUri: "yandex/album/36900389" Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioReplaceAndPlayItems Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreStateMachine::ClearQueue Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreStateMachine::stop Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreStateMachine::serviceStop Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreStateMachine::serviceStop trackBlock undefined Jun 19 10:24:40 ft1905-febf volumio[6639]: info: ControllerMpd::stop Jun 19 10:24:40 ft1905-febf volumio[6639]: verbose: ControllerMpd::sendMpdCommand stop Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CorePlayQueue::clearPlayQueue Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CorePlayQueue::saveQueue Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreCommandRouter::volumioPushQueue Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CoreStateMachine::addQueueItems Jun 19 10:24:40 ft1905-febf volumio[6639]: info: CorePlayQueue::addQueueItems Jun 19 10:24:40 ft1905-febf volumio[6639]: info: Exploding uri yandex/track/139792664 in service yandex Jun 19 10:24:40 ft1905-febf volumio[6639]: info: [1750299880679] ControllerYandexPlugin::explodeUri Jun 19 10:24:40 ft1905-febf volumio[6639]: info: explodeUri uri: yandex/track/139792664 Jun 19 10:24:40 ft1905-febf volumio[6639]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 19 10:24:40 ft1905-febf volumio[6639]: TypeError: thisPlugin.explodeUri(...).then(...).fail is not a function Jun 19 10:24:40 ft1905-febf volumio[6639]: at CoreCommandRouter.explodeUriFromService (webpack://Volumio2/./app/index.js?:1322:8) Jun 19 10:24:40 ft1905-febf volumio[6639]: at CorePlayQueue.addQueueItems (webpack://Volumio2/./app/playqueue.js?:146:48) Jun 19 10:24:40 ft1905-febf volumio[6639]: at CoreStateMachine.addQueueItems (webpack://Volumio2/./app/statemachine.js?:243:25) Jun 19 10:24:40 ft1905-febf volumio[6639]: at CoreCommandRouter.replaceAndPlay (webpack://Volumio2/./app/index.js?:505:23) Jun 19 10:24:40 ft1905-febf volumio[6639]: at CoreCommandRouter.playItemsList (webpack://Volumio2/./app/index.js?:481:17) Jun 19 10:24:40 ft1905-febf volumio[6639]: at Socket.eval (webpack://Volumio2/./app/plugins/user_interface/websocket/index.js?:111:35) Jun 19 10:24:40 ft1905-febf volumio[6639]: at Socket.emit (events.js:198:13) Jun 19 10:24:40 ft1905-febf volumio[6639]: at eval (webpack://Volumio2/./node_modules/socket.io/lib/socket.js?:503:12) Jun 19 10:24:40 ft1905-febf volumio[6639]: at process._tickCallback (internal/process/next_tick.js:61:11) Jun 19 10:24:40 ft1905-febf volumio[6639]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 19 10:24:41 ft1905-febf sudo[7300]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-19 10:23 Jun 19 10:24:42 ft1905-febf sudo[7300]: pam_unix(sudo:session): session opened for user root by (uid=0) NAME="Ubuntu" VERSION="20.04.5 LTS (Focal Fossa)" ID=ubuntu ID_LIKE=debian PRETTY_NAME="Ubuntu 20.04.5 LTS" VERSION_ID="20.04" HOME_URL="https://www.ubuntu.com/" SUPPORT_URL="https://help.ubuntu.com/" BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/" PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy" VERSION_CODENAME=focal UBUNTU_CODENAME=focal VOLUMIO_BUILD_VERSION="" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_BE_VERSION="3e944f35d34b575025d16b976b4cb4d9aed53b66" VOLUMIO_ARCH="armv7" VOLUMIO_VERSION=1.4.1.157 VOLUMIO_BUILD_DATE=2025-06-17 19:19:17 VOLUMIO_VARIANT=volumio VOLUMIO_HARDWARE=Generic DT based system