-- 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