-- Logs begin at Tue 2023-03-28 01:54:07 CST, end at Thu 2025-06-05 17:53:37 CST. -- Jun 05 17:52:04 ft1905-febf volumio[10859]: Device response: { METHOD: 'HTTP/1.1 200 OK', Jun 05 17:52:04 ft1905-febf volumio[10859]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:04 ft1905-febf volumio[10859]: LOCATION: 'http://192.168.4.85:3030/upnp/root.xml', Jun 05 17:52:04 ft1905-febf volumio[10859]: SERVER: 'Synaudio Music Service/1.0 UPnP/1.1 MusicService/1.0', Jun 05 17:52:04 ft1905-febf volumio[10859]: NT: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:04 ft1905-febf volumio[10859]: NTS: 'ssdp:alive', Jun 05 17:52:04 ft1905-febf volumio[10859]: UDN: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd', Jun 05 17:52:04 ft1905-febf volumio[10859]: USN: Jun 05 17:52:04 ft1905-febf volumio[10859]: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:04 ft1905-febf volumio[10859]: 'BOOTID.UPNP.ORG': '13456324', Jun 05 17:52:04 ft1905-febf volumio[10859]: 'CONFIGID.UPNP.ORG': '13456324', Jun 05 17:52:04 ft1905-febf volumio[10859]: EXT: '', Jun 05 17:52:04 ft1905-febf volumio[10859]: DATE: '2025-06-05T09:52:04.304971Z' } Jun 05 17:52:04 ft1905-febf volumio[10859]: Device IP: 192.168.4.85 Jun 05 17:52:06 ft1905-febf volumio[10859]: Device response: { EXT: '', Jun 05 17:52:06 ft1905-febf volumio[10859]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:06 ft1905-febf volumio[10859]: SERVER: 'Linux/5.4.259-qgki-g6f25851aad0d UPnP/1.0 BubbleUPnP/4.4.9', Jun 05 17:52:06 ft1905-febf volumio[10859]: USN: Jun 05 17:52:06 ft1905-febf volumio[10859]: 'uuid:da1e268e-e6e8-4a0f-ac9a-688b73f80eac::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:06 ft1905-febf volumio[10859]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:06 ft1905-febf volumio[10859]: LOCATION: Jun 05 17:52:06 ft1905-febf volumio[10859]: 'http://192.168.4.85:58645/dev/da1e268e-e6e8-4a0f-ac9a-688b73f80eac/desc.xml' } Jun 05 17:52:06 ft1905-febf volumio[10859]: Device IP: 192.168.4.85 Jun 05 17:52:22 ft1905-febf go-librespot[11195]: time="2025-06-05T17:52:22+08:00" level=trace msg="sent dealer ping" Jun 05 17:52:22 ft1905-febf go-librespot[11195]: time="2025-06-05T17:52:22+08:00" level=trace msg="received dealer pong" Jun 05 17:52:25 ft1905-febf sshd[12359]: rexec line 6: Deprecated option UsePrivilegeSeparation Jun 05 17:52:25 ft1905-febf sshd[12359]: rexec line 7: Deprecated option KeyRegenerationInterval Jun 05 17:52:25 ft1905-febf sshd[12359]: rexec line 8: Deprecated option ServerKeyBits Jun 05 17:52:25 ft1905-febf sshd[12359]: rexec line 14: Deprecated option RSAAuthentication Jun 05 17:52:25 ft1905-febf sshd[12359]: rexec line 17: Deprecated option RhostsRSAAuthentication Jun 05 17:52:25 ft1905-febf sshd[12359]: reprocess config line 14: Deprecated option RSAAuthentication Jun 05 17:52:25 ft1905-febf sshd[12359]: reprocess config line 17: Deprecated option RhostsRSAAuthentication Jun 05 17:52:26 ft1905-febf sshd[12359]: Accepted password for volumio from 192.168.4.28 port 57438 ssh2 Jun 05 17:52:26 ft1905-febf sshd[12359]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Jun 05 17:52:26 ft1905-febf systemd-logind[2182]: New session c5 of user volumio. Jun 05 17:52:26 ft1905-febf systemd[1]: Started Session c5 of user volumio. Jun 05 17:52:28 ft1905-febf sshd[12374]: Received disconnect from 192.168.4.28 port 57438:11: Jun 05 17:52:28 ft1905-febf sshd[12374]: Disconnected from user volumio 192.168.4.28 port 57438 Jun 05 17:52:28 ft1905-febf sshd[12359]: pam_unix(sshd:session): session closed for user volumio Jun 05 17:52:28 ft1905-febf sshd[12378]: rexec line 6: Deprecated option UsePrivilegeSeparation Jun 05 17:52:28 ft1905-febf sshd[12378]: rexec line 7: Deprecated option KeyRegenerationInterval Jun 05 17:52:28 ft1905-febf sshd[12378]: rexec line 8: Deprecated option ServerKeyBits Jun 05 17:52:28 ft1905-febf sshd[12378]: rexec line 14: Deprecated option RSAAuthentication Jun 05 17:52:28 ft1905-febf sshd[12378]: rexec line 17: Deprecated option RhostsRSAAuthentication Jun 05 17:52:28 ft1905-febf systemd-logind[2182]: Session c5 logged out. Waiting for processes to exit. Jun 05 17:52:28 ft1905-febf systemd[1]: session-c5.scope: Succeeded. Jun 05 17:52:28 ft1905-febf systemd-logind[2182]: Removed session c5. Jun 05 17:52:28 ft1905-febf sshd[12378]: reprocess config line 14: Deprecated option RSAAuthentication Jun 05 17:52:28 ft1905-febf sshd[12378]: reprocess config line 17: Deprecated option RhostsRSAAuthentication Jun 05 17:52:28 ft1905-febf sshd[12378]: Accepted password for volumio from 192.168.4.28 port 57444 ssh2 Jun 05 17:52:28 ft1905-febf sshd[12378]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Jun 05 17:52:28 ft1905-febf systemd-logind[2182]: New session c6 of user volumio. Jun 05 17:52:28 ft1905-febf systemd[1]: Started Session c6 of user volumio. Jun 05 17:52:28 ft1905-febf sudo[12405]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/systemctl stop volumio.service Jun 05 17:52:29 ft1905-febf sudo[12405]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:29 ft1905-febf systemd[1]: Stopping Volumio Backend Module... Jun 05 17:52:29 ft1905-febf socketio[2396]: [2025-06-05 17:52:29] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jun 05 17:52:29 ft1905-febf socketio[2396]: [2025-06-05 17:52:29] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jun 05 17:52:29 ft1905-febf go-librespot[11195]: time="2025-06-05T17:52:29+08:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Jun 05 17:52:29 ft1905-febf systemd[1]: volumio.service: Succeeded. Jun 05 17:52:29 ft1905-febf systemd[1]: Stopped Volumio Backend Module. Jun 05 17:52:29 ft1905-febf sudo[12405]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:29 ft1905-febf sudo[12414]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/usr/bin/systemctl start volumio.service Jun 05 17:52:29 ft1905-febf sudo[12414]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:29 ft1905-febf systemd[1]: Started dynamicswap service. Jun 05 17:52:29 ft1905-febf systemd[1]: Started Volumio Backend Module. Jun 05 17:52:29 ft1905-febf sudo[12414]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:29 ft1905-febf sshd[12402]: Received disconnect from 192.168.4.28 port 57444:11: Jun 05 17:52:29 ft1905-febf sshd[12402]: Disconnected from user volumio 192.168.4.28 port 57444 Jun 05 17:52:29 ft1905-febf sshd[12378]: pam_unix(sshd:session): session closed for user volumio Jun 05 17:52:29 ft1905-febf systemd[1]: dynamicswap.service: Succeeded. Jun 05 17:52:29 ft1905-febf systemd-logind[2182]: Session c6 logged out. Waiting for processes to exit. Jun 05 17:52:29 ft1905-febf systemd[1]: session-c6.scope: Succeeded. Jun 05 17:52:29 ft1905-febf systemd-logind[2182]: Removed session c6. Jun 05 17:52:33 ft1905-febf volumio[12426]: info: ------------------------------------------- Jun 05 17:52:33 ft1905-febf volumio[12426]: info: ----- Volumio2 ---- Jun 05 17:52:33 ft1905-febf volumio[12426]: info: ------------------------------------------- Jun 05 17:52:33 ft1905-febf volumio[12426]: info: ----- System startup ---- Jun 05 17:52:33 ft1905-febf volumio[12426]: info: ------------------------------------------- Jun 05 17:52:34 ft1905-febf socketio[2396]: [2025-06-05 17:52:34] [connect] Successful connection Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Found new core plugin music_service/cdplayer. Adding it Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Configured plugin music_service/cdplayer cannot be loaded. Removing from configuration Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Plugin folders cleanup Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning into folder /volumio/app/plugins/ Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category audio_interface Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category miscellanea Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category music_service Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category plugins.json Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category system_controller Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning category user_interface Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Scanning into folder /data/plugins/ Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Plugin folders cleanup completed Jun 05 17:52:34 ft1905-febf volumio[12426]: info: ------------------------------------------- Jun 05 17:52:34 ft1905-febf volumio[12426]: info: ----- Core plugins startup ---- Jun 05 17:52:34 ft1905-febf volumio[12426]: info: ------------------------------------------- Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Loading plugins from folder /volumio/app/plugins/ Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Adding plugin upnp to MyMusic Plugins Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Loading plugins from folder /data/plugins/ Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Loading plugin "system"... Jun 05 17:52:34 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/system/index.js Jun 05 17:52:34 ft1905-febf volumio[12426]: info: Loading plugin "appearance"... Jun 05 17:52:34 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/miscellanea/appearance/index.js Jun 05 17:52:35 ft1905-febf volumio[12426]: info: Loading plugin "network"... Jun 05 17:52:35 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/network/index.js Jun 05 17:52:35 ft1905-febf volumio[12426]: info: Refreshing Cached IP Addresses Jun 05 17:52:35 ft1905-febf sudo[12457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 05 17:52:35 ft1905-febf volumio[12426]: info: Loading plugin "services"... Jun 05 17:52:35 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/services/index.js Jun 05 17:52:35 ft1905-febf sudo[12457]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:35 ft1905-febf volumio[12426]: info: Loading plugin "alsa_controller"... Jun 05 17:52:35 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/audio_interface/alsa_controller/index.js Jun 05 17:52:35 ft1905-febf sudo[12457]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:35 ft1905-febf sudo[12462]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 05 17:52:35 ft1905-febf sudo[12462]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:35 ft1905-febf volumio[12426]: info: Applying required configuration parameters for plugin alsa_controller Jun 05 17:52:35 ft1905-febf sudo[12462]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Loading plugin "wizard"... Jun 05 17:52:36 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/miscellanea/wizard/index.js Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Loading plugin "volumio_command_line_client"... Jun 05 17:52:36 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/volumio_command_line_client/index.js Jun 05 17:52:36 ft1905-febf volumio[12426]: info: /volumio/app/plugins/system_controller/volumio_command_line_client/getvolumedb.sh.template Jun 05 17:52:36 ft1905-febf volumio[12426]: info: /volumio/app/plugins/system_controller/volumio_command_line_client/setvolumedb.sh.template Jun 05 17:52:36 ft1905-febf volumio[12426]: info: /volumio/app/plugins/system_controller/volumio_command_line_client/getvolume.sh.template Jun 05 17:52:36 ft1905-febf volumio[12426]: info: /volumio/app/plugins/system_controller/volumio_command_line_client/setvolume.sh.template Jun 05 17:52:36 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Loading plugin "upnp"... Jun 05 17:52:36 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/audio_interface/upnp/index.js Jun 05 17:52:36 ft1905-febf volumio[12426]: info: [1749117156317] Starting Upmpd Daemon Jun 05 17:52:36 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Loading plugin "my_music"... Jun 05 17:52:36 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/miscellanea/my_music/index.js Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Loading plugin "mpd"... Jun 05 17:52:36 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/mpd/index.js Jun 05 17:52:36 ft1905-febf volumio[12426]: info: Creating MPD Configuration file Jun 05 17:52:36 ft1905-febf sudo[12488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 05 17:52:37 ft1905-febf volumio[12426]: info: Loading plugin "upnp_browser"... Jun 05 17:52:37 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/upnp_browser/index.js Jun 05 17:52:37 ft1905-febf sudo[12488]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:37 ft1905-febf sudo[12488]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:37 ft1905-febf sudo[12493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 05 17:52:37 ft1905-febf sudo[12493]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:37 ft1905-febf systemd[1]: Stopping Music Player Daemon... Jun 05 17:52:37 ft1905-febf systemd[1]: mpd.service: Succeeded. Jun 05 17:52:37 ft1905-febf systemd[1]: Stopped Music Player Daemon. Jun 05 17:52:37 ft1905-febf systemd[1]: Starting Music Player Daemon... Jun 05 17:52:37 ft1905-febf volumio[12426]: info: Loading plugin "networkfs"... Jun 05 17:52:37 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/networkfs/index.js Jun 05 17:52:37 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 05 17:52:37 ft1905-febf volumio[12426]: info: Loading plugin "alarm-clock"... Jun 05 17:52:37 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/miscellanea/alarm-clock/index.js Jun 05 17:52:38 ft1905-febf volumio[12426]: info: Loading plugin "airplay_emulation"... Jun 05 17:52:38 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/airplay_emulation/index.js Jun 05 17:52:38 ft1905-febf volumio[12426]: Shairport Sync D-Bus 服务已注册。 Jun 05 17:52:38 ft1905-febf volumio[12426]: info: Starting Shairport Sync Jun 05 17:52:38 ft1905-febf volumio[12426]: info: Loading plugin "last_100"... Jun 05 17:52:38 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/last_100/index.js Jun 05 17:52:38 ft1905-febf volumio[12426]: info: Loading plugin "spop"... Jun 05 17:52:38 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/spop/index.js Jun 05 17:52:39 ft1905-febf volumio[12426]: info: Loading plugin "webradio"... Jun 05 17:52:39 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/webradio/index.js Jun 05 17:52:40 ft1905-febf mpd[12504]: Jun 05 17:52 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 05 17:52:40 ft1905-febf mpd[12504]: Jun 05 17:52 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Jun 05 17:52:40 ft1905-febf mpd[12504]: Jun 05 17:52 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Jun 05 17:52:40 ft1905-febf systemd[1]: Started Music Player Daemon. Jun 05 17:52:40 ft1905-febf sudo[12493]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "i2s_dacs"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/i2s_dacs/index.js Jun 05 17:52:41 ft1905-febf volumio[12426]: info: I2S DAC not set, start Auto-detection Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "volumiodiscovery"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/volumiodiscovery/index.js Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** For more information see Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** For more information see Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 05 17:52:41 ft1905-febf volumio[12426]: *** WARNING *** For more information see Jun 05 17:52:41 ft1905-febf node[12426]: *** WARNING *** For more information see Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Discovery: Started advertising with name: FT1905-febf Jun 05 17:52:41 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "outputs"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/audio_interface/outputs/index.js Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "albumart"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/miscellanea/albumart/index.js Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Plugin example_plugin is not enabled Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "inputs"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/inputs/index.js Jun 05 17:52:41 ft1905-febf volumio[12426]: info: Loading plugin "pandora"... Jun 05 17:52:41 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/pandora/index.js Jun 05 17:52:42 ft1905-febf volumio[12426]: info: Applying required configuration parameters for plugin pandora Jun 05 17:52:42 ft1905-febf volumio[12426]: info: Loading plugin "podcast"... Jun 05 17:52:42 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/podcast/index.js Jun 05 17:52:42 ft1905-febf volumio[12426]: info: ControllerPodcast::constructor Jun 05 17:52:42 ft1905-febf volumio[12426]: info: Loading plugin "qobuz"... Jun 05 17:52:42 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/qobuz/index.js Jun 05 17:52:42 ft1905-febf volumio[12426]: error: ATTENTION!!!: Plugin qobuz does not return adequate promise from onVolumioStart: please update! Jun 05 17:52:42 ft1905-febf volumio[12426]: info: Loading plugin "tidal"... Jun 05 17:52:42 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/music_service/tidal/index.js Jun 05 17:52:43 ft1905-febf volumio[12426]: info: [1749117163672] ControllerTidalPlugin::constructor Jun 05 17:52:43 ft1905-febf volumio[12426]: info: [1749117163675] ControllerTidalPlugin::onVolumioStart Jun 05 17:52:43 ft1905-febf volumio[12426]: info: Loading plugin "updater_comm"... Jun 05 17:52:43 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/system_controller/updater_comm/index.js Jun 05 17:52:43 ft1905-febf volumio[12426]: info: Plugin mpdemulation is not enabled Jun 05 17:52:43 ft1905-febf volumio[12426]: info: Loading plugin "rest_api"... Jun 05 17:52:43 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/user_interface/rest_api/index.js Jun 05 17:52:43 ft1905-febf volumio[12426]: info: Loading plugin "websocket"... Jun 05 17:52:43 ft1905-febf volumio[12426]: [ require ] /volumio/app/plugins/user_interface/websocket/index.js Jun 05 17:52:43 ft1905-febf volumio[12426]: info: ___________ START PLUGINS ___________ Jun 05 17:52:43 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 17:52:43 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:43 ft1905-febf volumio[12426]: info: [1749117163931] CoreMusicLibrary::Adding element Media Servers Jun 05 17:52:43 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:43 ft1905-febf volumio[12426]: SSDP Client initialized. Jun 05 17:52:43 ft1905-febf volumio[12426]: Starting initial SSDP search... Jun 05 17:52:43 ft1905-febf volumio[12426]: Discovering on interface: lo Jun 05 17:52:43 ft1905-febf volumio[12426]: Discovering on interface: eth0 Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164097] CoreMusicLibrary::Adding element Last_100 Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: Creating Spotify config file Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164139] CoreMusicLibrary::Adding element Webradio Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164167] CoreMusicLibrary::Adding element Pandora Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164174] ControllerPandora::initializeMQTT Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164176] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164195] CoreMusicLibrary::Adding element Podcast Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164202] CoreMusicLibrary::Adding element Qobuz Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164216] ControllerTidalPlugin::onStart Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164225] ControllerTidalPlugin::addToBrowseSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 05 17:52:44 ft1905-febf volumio[12426]: info: [1749117164227] CoreMusicLibrary::Adding element Tidal Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: Loading i18n strings for locale en Jun 05 17:52:44 ft1905-febf volumio[12426]: Updating browse sources language Jun 05 17:52:44 ft1905-febf volumio[12426]: Cannot find translation for sourceMedia Servers Jun 05 17:52:44 ft1905-febf volumio[12426]: Cannot find translation for sourcePodcast Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::initPlayerControls Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 05 17:52:44 ft1905-febf volumio[12426]: info: BOOT COMPLETED Jun 05 17:52:44 ft1905-febf volumio[12426]: [Metrics] CommandRouter: 11s 28.91ms Jun 05 17:52:44 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 17:52:44 ft1905-febf kernel: sunxi-spdif 2036000.spdif: active: 1 Jun 05 17:52:46 ft1905-febf go-librespot[11195]: time="2025-06-05T17:52:46+08:00" level=trace msg="received accesspoint ping" Jun 05 17:52:46 ft1905-febf go-librespot[11195]: time="2025-06-05T17:52:46+08:00" level=trace msg="received accesspoint pong ack" Jun 05 17:52:46 ft1905-febf socketio[2396]: [2025-06-05 17:52:46] [connect] Successful connection Jun 05 17:52:49 ft1905-febf volumio[12426]: Playing WAVE '/volumio/app/startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Jun 05 17:52:49 ft1905-febf volumio[12426]: info: CoreCommandRouter::Close All Modals sent Jun 05 17:52:49 ft1905-febf volumio[12426]: info: CoreCommandRouter::Close All Modals sent Jun 05 17:52:49 ft1905-febf volumio[12426]: Express server listening on port 3000 Jun 05 17:52:49 ft1905-febf volumio[12426]: [Metrics] WebUI: 17s 119.77ms Jun 05 17:52:49 ft1905-febf volumio[12426]: (node:12426) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Jun 05 17:52:50 ft1905-febf volumio[12426]: info: [1749117170039] ControllerPandora::validateAndSetAccountOptions Jun 05 17:52:50 ft1905-febf volumio[12426]: error: [1749117170043] [Pandora] validateAndSetAccountOptions: Need email address and password. See plugin settings. Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreStateMachine::resetVolumioState Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreStateMachine::getcurrentVolume Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioRetrievevolume Jun 05 17:52:50 ft1905-febf sudo[12667]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 17:52:50 ft1905-febf sudo[12667]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:50 ft1905-febf sudo[12667]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:50 ft1905-febf sudo[12671]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 05 17:52:50 ft1905-febf sudo[12671]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:50 ft1905-febf volumio[12426]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jun 05 17:52:50 ft1905-febf sudo[12671]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:50 ft1905-febf volumio[12426]: Device response: { METHOD: 'HTTP/1.1 200 OK', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:50 ft1905-febf volumio[12426]: LOCATION: 'http://192.168.4.85:3030/upnp/root.xml', Jun 05 17:52:50 ft1905-febf volumio[12426]: SERVER: 'Synaudio Music Service/1.0 UPnP/1.1 MusicService/1.0', Jun 05 17:52:50 ft1905-febf volumio[12426]: NT: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:50 ft1905-febf volumio[12426]: NTS: 'ssdp:alive', Jun 05 17:52:50 ft1905-febf volumio[12426]: UDN: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd', Jun 05 17:52:50 ft1905-febf volumio[12426]: USN: Jun 05 17:52:50 ft1905-febf volumio[12426]: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'BOOTID.UPNP.ORG': '13456370', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'CONFIGID.UPNP.ORG': '13456370', Jun 05 17:52:50 ft1905-febf volumio[12426]: EXT: '', Jun 05 17:52:50 ft1905-febf volumio[12426]: DATE: '2025-06-05T09:52:50.179834Z' } Jun 05 17:52:50 ft1905-febf volumio[12426]: Device IP: 192.168.4.85 Jun 05 17:52:50 ft1905-febf volumio[12426]: Device response: { METHOD: 'HTTP/1.1 200 OK', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:50 ft1905-febf volumio[12426]: LOCATION: 'http://192.168.4.85:3030/upnp/root.xml', Jun 05 17:52:50 ft1905-febf volumio[12426]: SERVER: 'Synaudio Music Service/1.0 UPnP/1.1 MusicService/1.0', Jun 05 17:52:50 ft1905-febf volumio[12426]: NT: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:50 ft1905-febf volumio[12426]: NTS: 'ssdp:alive', Jun 05 17:52:50 ft1905-febf volumio[12426]: UDN: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd', Jun 05 17:52:50 ft1905-febf volumio[12426]: USN: Jun 05 17:52:50 ft1905-febf volumio[12426]: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'BOOTID.UPNP.ORG': '13456370', Jun 05 17:52:50 ft1905-febf volumio[12426]: 'CONFIGID.UPNP.ORG': '13456370', Jun 05 17:52:50 ft1905-febf volumio[12426]: EXT: '', Jun 05 17:52:50 ft1905-febf volumio[12426]: DATE: '2025-06-05T09:52:50.488699Z' } Jun 05 17:52:50 ft1905-febf volumio[12426]: Device IP: 192.168.4.85 Jun 05 17:52:50 ft1905-febf volumio[12426]: info: this.stateMachine.currentVolume: null, vol: 0 Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreStateMachine::updateTrackBlock Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CorePlayQueue::getTrackBlock Jun 05 17:52:50 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioRetrievevolume Jun 05 17:52:51 ft1905-febf volumio[12426]: info: MPD Permissions set Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 05 17:52:51 ft1905-febf volumio[12426]: Device response: { EXT: '', Jun 05 17:52:51 ft1905-febf volumio[12426]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:51 ft1905-febf volumio[12426]: SERVER: 'Linux/5.4.259-qgki-g6f25851aad0d UPnP/1.0 BubbleUPnP/4.4.9', Jun 05 17:52:51 ft1905-febf volumio[12426]: USN: Jun 05 17:52:51 ft1905-febf volumio[12426]: 'uuid:da1e268e-e6e8-4a0f-ac9a-688b73f80eac::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:51 ft1905-febf volumio[12426]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:51 ft1905-febf volumio[12426]: LOCATION: Jun 05 17:52:51 ft1905-febf volumio[12426]: 'http://192.168.4.85:58645/dev/da1e268e-e6e8-4a0f-ac9a-688b73f80eac/desc.xml' } Jun 05 17:52:51 ft1905-febf volumio[12426]: Device IP: 192.168.4.85 Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf socketio[2396]: [2025-06-05 17:52:51] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1749117166 101 Jun 05 17:52:51 ft1905-febf socketio[2396]: sio connected Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf socketio[2396]: socket send Jun 05 17:52:51 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:51 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:51 ft1905-febf socketio[2396]: { Jun 05 17:52:51 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:51 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:51 ft1905-febf socketio[2396]: }] Jun 05 17:52:51 ft1905-febf socketio[2396]: } Jun 05 17:52:51 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:51 ft1905-febf socketio[2396]: socket send Jun 05 17:52:51 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:51 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:51 ft1905-febf socketio[2396]: { Jun 05 17:52:51 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:51 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:51 ft1905-febf socketio[2396]: }, { Jun 05 17:52:51 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:51 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:51 ft1905-febf socketio[2396]: }] Jun 05 17:52:51 ft1905-febf socketio[2396]: } Jun 05 17:52:51 ft1905-febf volumio[12426]: info: Cannot read I2C interface or I2C interface not presentError: Command failed: /usr/bin/sudo /usr/sbin/i2cdetect -y 1 Jun 05 17:52:51 ft1905-febf volumio[12426]: sudo: /usr/sbin/i2cdetect: command not found Jun 05 17:52:51 ft1905-febf volumio[12426]: info: Spotify config file written Jun 05 17:52:51 ft1905-febf volumio[12426]: Device response: { EXT: '', Jun 05 17:52:51 ft1905-febf volumio[12426]: ST: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:51 ft1905-febf volumio[12426]: SERVER: 'Linux/5.4.259-qgki-g6f25851aad0d UPnP/1.0 BubbleUPnP/4.4.9', Jun 05 17:52:51 ft1905-febf volumio[12426]: USN: Jun 05 17:52:51 ft1905-febf volumio[12426]: 'uuid:da1e268e-e6e8-4a0f-ac9a-688b73f80eac::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:52:51 ft1905-febf volumio[12426]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:52:51 ft1905-febf volumio[12426]: LOCATION: Jun 05 17:52:51 ft1905-febf volumio[12426]: 'http://192.168.4.85:58645/dev/da1e268e-e6e8-4a0f-ac9a-688b73f80eac/desc.xml' } Jun 05 17:52:51 ft1905-febf volumio[12426]: Device IP: 192.168.4.85 Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:51 ft1905-febf sudo[12708]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart go-librespot-daemon.service Jun 05 17:52:51 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:51 ft1905-febf sudo[12708]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:52 ft1905-febf systemd[1]: Stopping go-librespot Daemon... Jun 05 17:52:52 ft1905-febf systemd[1]: go-librespot-daemon.service: Succeeded. Jun 05 17:52:52 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 05 17:52:52 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 05 17:52:52 ft1905-febf sudo[12708]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:52 ft1905-febf go-librespot[12714]: go-librespot daemon starting... Jun 05 17:52:52 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:52+08:00" level=info msg="running go-librespot 0.2.0" Jun 05 17:52:52 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:52+08:00" level=debug msg="app state loaded" Jun 05 17:52:52 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:52+08:00" level=debug msg="stored credentials not found" Jun 05 17:52:52 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:52+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 05 17:52:52 ft1905-febf volumio[12694]: Forking 1 albumart workers Jun 05 17:52:52 ft1905-febf volumio[12426]: sendCommand: Command { name: 'playlistinfo', args: [] } Jun 05 17:52:52 ft1905-febf volumio[12426]: sendCommand: Command { name: 'lsinfo "USB"', args: [] } Jun 05 17:52:52 ft1905-febf volumio[12426]: sendCommand: Command { name: 'search album ""', args: [] } Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:52 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:52 ft1905-febf socketio[2396]: socket send Jun 05 17:52:52 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:52 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:52 ft1905-febf socketio[2396]: { Jun 05 17:52:52 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:52 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:52 ft1905-febf socketio[2396]: }] Jun 05 17:52:52 ft1905-febf socketio[2396]: } Jun 05 17:52:52 ft1905-febf socketio[2396]: socket send Jun 05 17:52:52 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:52 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:52 ft1905-febf socketio[2396]: { Jun 05 17:52:52 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:52 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:52 ft1905-febf socketio[2396]: }, { Jun 05 17:52:52 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:52 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:52 ft1905-febf socketio[2396]: }] Jun 05 17:52:52 ft1905-febf socketio[2396]: } Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:52 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:52 ft1905-febf volumio[12426]: info: MPD running with PID12504 Jun 05 17:52:52 ft1905-febf volumio[12426]: ,establishing connection Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jun 05 17:52:52 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:52 ft1905-febf volumio[12426]: info: No need to fix Spotify hosts Jun 05 17:52:52 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:52 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:52 ft1905-febf volumio[12426]: error: updateQueue error: null Jun 05 17:52:52 ft1905-febf volumio[12426]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreStateMachine::setRepeat null single undefined Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreStateMachine::setRandom false Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:52:53 ft1905-febf socketio[2396]: socket send Jun 05 17:52:53 ft1905-febf socketio[2396]: socket send Jun 05 17:52:53 ft1905-febf volumio[12426]: sendCommand: Command { name: 'playlistinfo', args: [] } Jun 05 17:52:53 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:53 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:53 ft1905-febf socketio[2396]: socket send Jun 05 17:52:53 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:53 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:53 ft1905-febf socketio[2396]: { Jun 05 17:52:53 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:53 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:53 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:53 ft1905-febf socketio[2396]: }, { Jun 05 17:52:53 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:53 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:53 ft1905-febf socketio[2396]: }] Jun 05 17:52:53 ft1905-febf socketio[2396]: } Jun 05 17:52:53 ft1905-febf volumio[12426]: error: updateQueue error: null Jun 05 17:52:53 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:54 ft1905-febf volumio[12426]: info: Starting Shairport Sync Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 05 17:52:54 ft1905-febf sudo[12742]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 05 17:52:54 ft1905-febf sudo[12742]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:54 ft1905-febf sudo[12740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 05 17:52:54 ft1905-febf volumio[12426]: Discovery: adding 28bc41e0-af37-44db-b28c-6c26e99ff0b2 Jun 05 17:52:54 ft1905-febf sudo[12740]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:52:54 ft1905-febf volumio[12426]: info: mDNS: Found device FT1905-febf Jun 05 17:52:54 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:54 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 05 17:52:54 ft1905-febf systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 05 17:52:54 ft1905-febf sudo[12740]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:54 ft1905-febf systemd[1]: shairport-sync.service: Succeeded. Jun 05 17:52:54 ft1905-febf systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioGetVisibleSources Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:54 ft1905-febf systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 05 17:52:54 ft1905-febf sudo[12742]: pam_unix(sudo:session): session closed for user root Jun 05 17:52:54 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getToneInfo","index":5,"getinfo":4} Jun 05 17:52:54 ft1905-febf socketio[2396]: socket send Jun 05 17:52:54 ft1905-febf socketio[2396]: command_len 56 Jun 05 17:52:54 ft1905-febf socketio[2396]: pushToneInfo Jun 05 17:52:54 ft1905-febf socketio[2396]: { Jun 05 17:52:54 ft1905-febf socketio[2396]: "volume": 43, Jun 05 17:52:54 ft1905-febf socketio[2396]: "bass": 0, Jun 05 17:52:54 ft1905-febf socketio[2396]: "treble": 0 Jun 05 17:52:54 ft1905-febf socketio[2396]: } Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 05 17:52:54 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioGetQueue Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CoreStateMachine::getQueue Jun 05 17:52:54 ft1905-febf volumio[12426]: info: CorePlayQueue::getQueue Jun 05 17:52:54 ft1905-febf volumio[12426]: info: Listing playlists Jun 05 17:52:54 ft1905-febf volumio[12724]: Starting albumart workers Jun 05 17:52:55 ft1905-febf volumio[12426]: Discovery: this is already registered, 28bc41e0-af37-44db-b28c-6c26e99ff0b2 Jun 05 17:52:55 ft1905-febf volumio[12426]: info: mDNS: Found device FT1905-febf Jun 05 17:52:55 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:55 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:55 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:52:55 ft1905-febf socketio[2396]: socket send Jun 05 17:52:55 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:52:55 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:52:55 ft1905-febf socketio[2396]: { Jun 05 17:52:55 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:52:55 ft1905-febf socketio[2396]: } Jun 05 17:52:55 ft1905-febf volumio[12426]: info: this.stateMachine.currentVolume: 0, vol: 43 Jun 05 17:52:55 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:55 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 05 17:52:55 ft1905-febf volumio[12426]: info: [{"vol":43}] Jun 05 17:52:55 ft1905-febf volumio[12426]: info: [pushCmd] {"index":4,"volume":43} Jun 05 17:52:55 ft1905-febf socketio[2396]: socket send Jun 05 17:52:55 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:52:55 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:52:55 ft1905-febf volumio[12426]: info: [pushToneInfo] {"bass":0,"treble":0,"volume":43} Jun 05 17:52:55 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:52:55 ft1905-febf socketio[2396]: socket send Jun 05 17:52:55 ft1905-febf volumio[12426]: info: Shairport-Sync Started Jun 05 17:52:55 ft1905-febf volumio[12426]: Error adding Membership: Error: addMembership EINVAL Jun 05 17:52:55 ft1905-febf volumio[12426]: info: Upmpdcli Daemon Started Jun 05 17:52:55 ft1905-febf socketio[2396]: socket send Jun 05 17:52:56 ft1905-febf volumio[12426]: info: go-librespot daemon successfully initialized Jun 05 17:52:58 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:58+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 17:52:58 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:58+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 17:52:58 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:58+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 17:52:58 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:58+08:00" level=info msg="zeroconf server listening on port 41497" Jun 05 17:52:59 ft1905-febf volumio[12426]: info: Initializing connection to go-librespot Websocket Jun 05 17:52:59 ft1905-febf go-librespot[12716]: time="2025-06-05T17:52:59+08:00" level=debug msg="new websocket client" Jun 05 17:52:59 ft1905-febf volumio[12426]: info: Connection to go-librespot Websocket established Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:52:59 ft1905-febf socketio[2396]: socket send Jun 05 17:52:59 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:52:59 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:52:59 ft1905-febf socketio[2396]: { Jun 05 17:52:59 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:52:59 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:52:59 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:52:59 ft1905-febf socketio[2396]: }, { Jun 05 17:52:59 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:52:59 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:52:59 ft1905-febf socketio[2396]: }] Jun 05 17:52:59 ft1905-febf socketio[2396]: } Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::volumioGetVisibleSources Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getToneInfo","index":5,"getinfo":4} Jun 05 17:52:59 ft1905-febf socketio[2396]: socket send Jun 05 17:52:59 ft1905-febf socketio[2396]: command_len 56 Jun 05 17:52:59 ft1905-febf socketio[2396]: pushToneInfo Jun 05 17:52:59 ft1905-febf socketio[2396]: { Jun 05 17:52:59 ft1905-febf socketio[2396]: "volume": 43, Jun 05 17:52:59 ft1905-febf socketio[2396]: "bass": 0, Jun 05 17:52:59 ft1905-febf socketio[2396]: "treble": 0 Jun 05 17:52:59 ft1905-febf socketio[2396]: } Jun 05 17:52:59 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jun 05 17:52:59 ft1905-febf volumio[12426]: error: Could not retrieve plugin audio_interface multiroom Jun 05 17:52:59 ft1905-febf volumio[12426]: info: Listing playlists Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:52:59 ft1905-febf socketio[2396]: socket send Jun 05 17:52:59 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:52:59 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:52:59 ft1905-febf socketio[2396]: { Jun 05 17:52:59 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:52:59 ft1905-febf socketio[2396]: } Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushToneInfo] {"bass":0,"treble":0,"volume":43} Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:52:59 ft1905-febf socketio[2396]: socket send Jun 05 17:52:59 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:52:59 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:52:59 ft1905-febf socketio[2396]: { Jun 05 17:52:59 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:52:59 ft1905-febf socketio[2396]: } Jun 05 17:52:59 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=debug msg="obtained new client token: AABd2jSrSOdRcx/2N9euIwRdGt9Wqc5Gv0VvJZgBaqD8hkZ1xTuwMnCJ4TblW0Xr8vhr4MiAujD2uqJu6ggGbPhuo8VU3xuqf62LQAclMniOaLM7IRm1X4u8bHNTuxFc0bgN4jS0asyxz3nCSnX92Pua8NYF1e90r/NSMTxJTakJQWUitvI0l6sytsEpTitMD5/m5nVvkD7jRqRcE+IYOOkATVwWv19p2NGtF40lAvJT9adL/E8yOkc3ADpk" Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=debug msg="completed keyexchange" Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=debug msg="completed challenge" Jun 05 17:53:02 ft1905-febf volumio[12426]: info: Getting Spotify volume Jun 05 17:53:02 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:53:02 ft1905-febf socketio[2396]: socket send Jun 05 17:53:02 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:53:02 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:53:02 ft1905-febf socketio[2396]: { Jun 05 17:53:02 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:53:02 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:53:02 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:53:02 ft1905-febf socketio[2396]: }, { Jun 05 17:53:02 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:53:02 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:53:02 ft1905-febf socketio[2396]: }] Jun 05 17:53:02 ft1905-febf socketio[2396]: } Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=info msg="authenticated AP as 31dobbykadpjqbg53ytmzna3bo7u" Jun 05 17:53:02 ft1905-febf socketio[2396]: socket send Jun 05 17:53:02 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:53:02 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:53:02 ft1905-febf socketio[2396]: { Jun 05 17:53:02 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:53:02 ft1905-febf socketio[2396]: } Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:53:02 ft1905-febf socketio[2396]: socket send Jun 05 17:53:02 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:53:02 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:53:02 ft1905-febf socketio[2396]: { Jun 05 17:53:02 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:53:02 ft1905-febf socketio[2396]: } Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:53:02 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:53:02 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:02 ft1905-febf volumio[12426]: SPOTIFY: SPOTIFY VOLUME undefined Jun 05 17:53:02 ft1905-febf volumio[12426]: SPOTIFY: VOLUMIO VOLUME 43 Jun 05 17:53:02 ft1905-febf volumio[12426]: info: Aligning Spotify Volume to Volumio Volume Jun 05 17:53:02 ft1905-febf volumio[12426]: info: Setting Spotify Volume from Volumio: 43 Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=info msg="authenticated Login5 as 31dobbykadpjqbg53ytmzna3bo7u" Jun 05 17:53:02 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:02+08:00" level=info msg="accepted zeroconf user 31dobbykadpjqbg53ytmzna3bo7u from iQOO 13" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="dealer connection opened" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=trace msg="starting accesspoint recv loop" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=trace msg="starting dealer recv loop" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=trace msg="received accesspoint ping" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=debug msg="received connection id: YzQ3NWVlMmEtYTRmMy00ZDg2LWFjN2MtNGRjZDFlNzZiNjVjK2RlYWxlcit0Y3A6Ly8wYWM5NDk0OC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArMjdDOTYyMTNFN0UxQTdDNEE1QTI1RTc5Mjg4RTg5NzdDMUY1REE1NzlDQkE5NTkzNzYwRDg4NTNFQzdFQjUwMQ==" Jun 05 17:53:03 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:03+08:00" level=trace msg="received accesspoint pong ack" Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=debug msg="put connect state because NEW_DEVICE" Jun 05 17:53:04 ft1905-febf volumio[12426]: SPOTIFY: SETTING SPOTIFY VOLUME 43 Jun 05 17:53:04 ft1905-febf volumio[12426]: info: Sending Spotify command with payload to local API: /player/volume Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=debug msg="update volume to 28180/65535" Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=debug msg="handling transfer player command from 13db9b7c8f69fb0f08b58b2838ef8017b5b60605" Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1DWSBcxmKiZ0B8" Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=trace msg="fetched new page 0 with 101 items (list: 101)" uri="spotify:playlist:37i9dQZF1DWSBcxmKiZ0B8" Jun 05 17:53:04 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:04+08:00" level=debug msg="loading track (paused: true, position: 81317ms)" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=trace msg="emitting websocket event: will_play" Jun 05 17:53:05 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","play_origin":"playlist"}} Jun 05 17:53:05 ft1905-febf volumio[12426]: info: Spotify is playing in volatile mode Jun 05 17:53:05 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:05 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:05 ft1905-febf volumio[12426]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 17:53:05 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:05 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Jun 05 17:53:05 ft1905-febf volumio[12426]: verbose: SET VOLATILE Jun 05 17:53:05 ft1905-febf volumio[12426]: info: CoreStateMachine::stop Jun 05 17:53:05 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:05 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:05 ft1905-febf volumio[12426]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 17:53:05 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:05 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:05 ft1905-febf volumio[12426]: verbose: UNSET VOLATILE Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="selected format OGG_VORBIS_320 (ec1388e8e930dea298eb8287aa0bb9b1033a5eca)" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="requested aes key for file ec1388e8e930dea298eb8287aa0bb9b1033a5eca, gid: 3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1700" Jun 05 17:53:05 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:05+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1296" Jun 05 17:53:06 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:06+08:00" level=debug msg="fetched first chunk of 19, total size is 9566620 bytes" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 8/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 5/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=trace msg="seek to 81317ms (diff: 119ms, samples: 3586079, bytes: 3015060)" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="created new output device" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=info msg="loaded track \"珊瑚海\" (paused: true, position: 81317ms, duration: 256333ms, prefetched: false)" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 7/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="fetched chunk 6/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=trace msg="emitting websocket event: metadata" Jun 05 17:53:07 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","name":"珊瑚海","artist_names":["Jay Chou","Lara Liang"],"album_name":"11月的蕭邦","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","position":81317,"duration":256333,"release_date":"year:2005 month:11 day:11","track_number":10,"disc_number":1}} Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=trace msg="emitting websocket event: active" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="sending successful reply for dealer request" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jun 05 17:53:07 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"active","data":null} Jun 05 17:53:07 ft1905-febf volumio[12426]: info: Aligning Spotify Volume to Volumio Volume Jun 05 17:53:07 ft1905-febf volumio[12426]: info: Setting Spotify Volume from Volumio: 43 Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 05 17:53:07 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:07+08:00" level=trace msg="emitting websocket event: volume" Jun 05 17:53:07 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"volume","data":{"value":43,"max":100}} Jun 05 17:53:07 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED SPOTIFY VOLUME 43 Jun 05 17:53:08 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:08+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 17:53:08 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:08+08:00" level=trace msg="emitting websocket event: paused" Jun 05 17:53:08 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","play_origin":"playlist"}} Jun 05 17:53:08 ft1905-febf volumio[12426]: info: Spotify is playing in volatile mode Jun 05 17:53:08 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:08 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:08 ft1905-febf volumio[12426]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 05 17:53:08 ft1905-febf volumio[12426]: !! !! Jun 05 17:53:08 ft1905-febf volumio[12426]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Jun 05 17:53:08 ft1905-febf volumio[12426]: verbose: SET VOLATILE Jun 05 17:53:08 ft1905-febf volumio[12426]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 17:53:08 ft1905-febf volumio[12426]: SPOTIFY: {"status":"pause","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jun 05 17:53:08 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: pause Jun 05 17:53:08 ft1905-febf volumio[12426]: this.volatileState: {"stream":false,"trackType":"","albumart":"/albumart","repeatMode":"all"} Jun 05 17:53:08 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:08 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:08 ft1905-febf socketio[2396]: socket send Jun 05 17:53:08 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:09 ft1905-febf volumio[12426]: SPOTIFY: SETTING SPOTIFY VOLUME 43 Jun 05 17:53:09 ft1905-febf volumio[12426]: info: Sending Spotify command with payload to local API: /player/volume Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="update volume to 28180/65535" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="handling resume player command from 13db9b7c8f69fb0f08b58b2838ef8017b5b60605" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=trace msg="seek to 81317ms (diff: 119ms, samples: 3586079, bytes: 3015060)" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:09 ft1905-febf kernel: sunxi-spdif 2036000.spdif: active: 1 Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="resume track at 81198ms" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=trace msg="scheduling prefetch in 145s" Jun 05 17:53:09 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:09+08:00" level=debug msg="sending successful reply for dealer request" Jun 05 17:53:10 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:10+08:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jun 05 17:53:10 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:10+08:00" level=trace msg="emitting websocket event: playing" Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","play_origin":"playlist"}} Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: {"status":"play","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 17:53:10 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:10 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 17:53:10 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:10 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:10 ft1905-febf socketio[2396]: socket send Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: PUSH STATE SPOTIFY Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: {"status":"play","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 17:53:10 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:10 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 17:53:10 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:10 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:10 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:10+08:00" level=debug msg="put connect state because VOLUME_CHANGED" Jun 05 17:53:10 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:10+08:00" level=trace msg="emitting websocket event: volume" Jun 05 17:53:10 ft1905-febf socketio[2396]: socket send Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: received: {"type":"volume","data":{"value":43,"max":100}} Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED SPOTIFY VOLUME 43 Jun 05 17:53:10 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:12 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:12+08:00" level=debug msg="fetched chunk 9/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:14 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 05 17:53:14 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 05 17:53:26 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:26+08:00" level=debug msg="fetched chunk 10/18, size: 524288" uri="spotify:track:3Qj9Fy8BPbWmICTiNkuqB7" Jun 05 17:53:28 ft1905-febf shairport-sync[12757]: warning: The output device "plughw:2,0" is busy and can't be used by Shairport Sync at present. Jun 05 17:53:28 ft1905-febf volumio[12426]: info: Airplay started streaming, receiving metadatas Jun 05 17:53:28 ft1905-febf volumio[12426]: info: [AirPlay] Preparing playback. Current service: spop Jun 05 17:53:28 ft1905-febf volumio[12426]: info: [AirPlay] Stopping previous service: Jun 05 17:53:28 ft1905-febf volumio[12426]: verbose: SET VOLATILE Jun 05 17:53:28 ft1905-febf volumio[12426]: info: CoreStateMachine::stop Jun 05 17:53:28 ft1905-febf volumio[12426]: info: CoreStateMachine::serviceStop Jun 05 17:53:28 ft1905-febf volumio[12426]: info: CoreCommandRouter::serviceStop Jun 05 17:53:28 ft1905-febf shairport-sync[12837]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 05 17:53:28 ft1905-febf shairport-sync[12837]: Dload Upload Total Spent Left Speed Jun 05 17:53:28 ft1905-febf volumio[12426]: info: Spotify Stop Jun 05 17:53:28 ft1905-febf volumio[12426]: SPOTIFY: SPOTIFY STOP Jun 05 17:53:28 ft1905-febf volumio[12426]: SPOTIFY: {"status":"play","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":81317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":43,"dbVolume":null,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Jun 05 17:53:28 ft1905-febf volumio[12426]: info: Sending Spotify command to local API: /player/pause Jun 05 17:53:28 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:28 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"spop","title":"珊瑚海","artist":"Jay Chou, Lara Liang","album":"11月的蕭邦","albumart":"https://i.scdn.co/image/ab67616d00001e022642de36b3fed494f653b015","uri":"spotify:track:3Qj9Fy8BPbWmICTiNkuqB7","trackType":"spotify","seek":99317,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jun 05 17:53:28 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:28 ft1905-febf shairport-sync[12837]: [79B blob data] Jun 05 17:53:28 ft1905-febf shairport-sync[12839]: % Total % Received % Xferd Average Speed Time Time Time Current Jun 05 17:53:28 ft1905-febf shairport-sync[12839]: Dload Upload Total Spent Left Speed Jun 05 17:53:28 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:28 ft1905-febf sudo[12840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl restart go-librespot-daemon.service Jun 05 17:53:28 ft1905-febf socketio[2396]: socket send Jun 05 17:53:29 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:29 ft1905-febf go-librespot[12716]: time="2025-06-05T17:53:29+08:00" level=debug msg="pause track at 100735ms" Jun 05 17:53:29 ft1905-febf sudo[12840]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 05 17:53:29 ft1905-febf volumio[12426]: info: Jun 05 17:53:29 ft1905-febf volumio[12426]: ---------------------------- Client requests Start Airplay PlaybackRoutine Jun 05 17:53:29 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Jun 05 17:53:29 ft1905-febf volumio[12426]: info: Received startAirplayPlayback: Jun 05 17:53:29 ft1905-febf shairport-sync[12839]: [79B blob data] Jun 05 17:53:29 ft1905-febf shairport-sync[12837]: [79B blob data] Jun 05 17:53:29 ft1905-febf volumio[12426]: info: Jun 05 17:53:29 ft1905-febf volumio[12426]: ---------------------------- Client requests AirplayActive Jun 05 17:53:29 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , setAirplayActive Jun 05 17:53:29 ft1905-febf shairport-sync[12837]: {"time":1749117209164,"response":"startAirplayPlayback Success"} Jun 05 17:53:29 ft1905-febf shairport-sync[12839]: [79B blob data] Jun 05 17:53:29 ft1905-febf systemd[1]: Stopping go-librespot Daemon... Jun 05 17:53:29 ft1905-febf systemd[1]: go-librespot-daemon.service: Killing process 12723 (go-librespot) with signal SIGKILL. Jun 05 17:53:29 ft1905-febf volumio[12426]: error: Failed to send command to Spotify local API: /player/pause: Error: socket hang up Jun 05 17:53:29 ft1905-febf systemd[1]: go-librespot-daemon.service: Succeeded. Jun 05 17:53:29 ft1905-febf systemd[1]: Stopped go-librespot Daemon. Jun 05 17:53:29 ft1905-febf volumio[12426]: info: Connection to go-librespot Websocket closed Jun 05 17:53:29 ft1905-febf systemd[1]: Started go-librespot Daemon. Jun 05 17:53:29 ft1905-febf sudo[12840]: pam_unix(sudo:session): session closed for user root Jun 05 17:53:29 ft1905-febf go-librespot[12848]: go-librespot daemon starting... Jun 05 17:53:29 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:29+08:00" level=info msg="running go-librespot 0.2.0" Jun 05 17:53:29 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:29+08:00" level=debug msg="app state loaded" Jun 05 17:53:29 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:29+08:00" level=debug msg="stored credentials not found" Jun 05 17:53:29 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:29+08:00" level=info msg="api server listening on 127.0.0.1:9879" Jun 05 17:53:29 ft1905-febf kernel: sunxi-spdif 2036000.spdif: active: 1 Jun 05 17:53:29 ft1905-febf shairport-sync[12839]: {"time":1749117209216,"response":"airplayActive Success"} Jun 05 17:53:29 ft1905-febf shairport-sync[12757]: warning: The output device "plughw:2,0" is no longer busy and will be used by Shairport Sync. Jun 05 17:53:30 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:30+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jun 05 17:53:30 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:30+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jun 05 17:53:30 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:30+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jun 05 17:53:30 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:30+08:00" level=info msg="zeroconf server listening on port 39893" Jun 05 17:53:31 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:31 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"低头呢喃","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":2000,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:31 ft1905-febf socketio[2396]: socket send Jun 05 17:53:31 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:31 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"低头呢喃","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":108000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:31 ft1905-febf socketio[2396]: socket send Jun 05 17:53:31 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:31 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"低头呢喃","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":108000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:31 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:31 ft1905-febf socketio[2396]: socket send Jun 05 17:53:31 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:31 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:31 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:32 ft1905-febf volumio[12426]: info: Initializing connection to go-librespot Websocket Jun 05 17:53:32 ft1905-febf go-librespot[12852]: time="2025-06-05T17:53:32+08:00" level=debug msg="new websocket client" Jun 05 17:53:32 ft1905-febf volumio[12426]: info: Connection to go-librespot Websocket established Jun 05 17:53:33 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:33 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"对你的偏爱太过于明目张胆","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":110000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:33 ft1905-febf socketio[2396]: socket send Jun 05 17:53:33 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:33 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"对你的偏爱太过于明目张胆","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":111000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:33 ft1905-febf socketio[2396]: socket send Jun 05 17:53:33 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:33 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:33 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:33 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"对你的偏爱太过于明目张胆","artist":"小半 — 陈粒","album":"小梦大半","albumart":"/albumart?cacheid=859&web=%E5%B0%8F%E5%8D%8A%20%E2%80%94%20%E9%99%88%E7%B2%92/%E5%B0%8F%E6%A2%A6%E5%A4%A7%E5%8D%8A/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":111000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:33 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:33 ft1905-febf socketio[2396]: socket send Jun 05 17:53:33 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:34 ft1905-febf volumio[12426]: Device response: { METHOD: 'HTTP/1.1 200 OK', Jun 05 17:53:34 ft1905-febf volumio[12426]: 'CACHE-CONTROL': 'max-age=1800', Jun 05 17:53:34 ft1905-febf volumio[12426]: LOCATION: 'http://192.168.4.85:3030/upnp/root.xml', Jun 05 17:53:34 ft1905-febf volumio[12426]: SERVER: 'Synaudio Music Service/1.0 UPnP/1.1 MusicService/1.0', Jun 05 17:53:34 ft1905-febf volumio[12426]: NT: 'urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:53:34 ft1905-febf volumio[12426]: NTS: 'ssdp:alive', Jun 05 17:53:34 ft1905-febf volumio[12426]: UDN: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd', Jun 05 17:53:34 ft1905-febf volumio[12426]: USN: Jun 05 17:53:34 ft1905-febf volumio[12426]: 'uuid:4a19d95b-5cca-5e42-ad08-dc352c14e5bd::urn:schemas-upnp-org:device:MediaServer:1', Jun 05 17:53:34 ft1905-febf volumio[12426]: 'BOOTID.UPNP.ORG': '13456414', Jun 05 17:53:34 ft1905-febf volumio[12426]: 'CONFIGID.UPNP.ORG': '13456414', Jun 05 17:53:34 ft1905-febf volumio[12426]: EXT: '', Jun 05 17:53:34 ft1905-febf volumio[12426]: DATE: '2025-06-05T09:53:34.009277Z' } Jun 05 17:53:34 ft1905-febf volumio[12426]: Device IP: 192.168.4.85 Jun 05 17:53:35 ft1905-febf volumio[12426]: info: Getting Spotify volume Jun 05 17:53:35 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworkMode Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushCmd] {"index":5,"getInfo":0} Jun 05 17:53:35 ft1905-febf socketio[2396]: socket send Jun 05 17:53:35 ft1905-febf socketio[2396]: command_len 356 Jun 05 17:53:35 ft1905-febf socketio[2396]: pushSrctotal Jun 05 17:53:35 ft1905-febf socketio[2396]: { Jun 05 17:53:35 ft1905-febf socketio[2396]: "total": 7, Jun 05 17:53:35 ft1905-febf socketio[2396]: "cur": 0, Jun 05 17:53:35 ft1905-febf socketio[2396]: "source": [{ Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "Media Player" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 4, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "Bluetooth" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 6, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "AUX" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "DIGITAL OPT1" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "DIGITAL OPT2" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 5, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "HDMI ARC" Jun 05 17:53:35 ft1905-febf socketio[2396]: }, { Jun 05 17:53:35 ft1905-febf socketio[2396]: "type": 0, Jun 05 17:53:35 ft1905-febf socketio[2396]: "name": "USB" Jun 05 17:53:35 ft1905-febf socketio[2396]: }] Jun 05 17:53:35 ft1905-febf socketio[2396]: } Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushSrctotal] {"cur":0,"source":[{"name":"Media Player","type":0},{"name":"Bluetooth","type":4},{"name":"AUX","type":6},{"name":"DIGITAL OPT1","type":5},{"name":"DIGITAL OPT2","type":5},{"name":"HDMI ARC","type":5},{"name":"USB","type":0}],"total":7} Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:53:35 ft1905-febf socketio[2396]: socket send Jun 05 17:53:35 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:53:35 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:53:35 ft1905-febf socketio[2396]: { Jun 05 17:53:35 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:53:35 ft1905-febf socketio[2396]: } Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushCmd] {"desc":"getSourceInfo","index":5,"getinfo":1} Jun 05 17:53:35 ft1905-febf socketio[2396]: socket send Jun 05 17:53:35 ft1905-febf socketio[2396]: command_len 31 Jun 05 17:53:35 ft1905-febf socketio[2396]: pushSourceInfo Jun 05 17:53:35 ft1905-febf socketio[2396]: { Jun 05 17:53:35 ft1905-febf socketio[2396]: "source": 0 Jun 05 17:53:35 ft1905-febf socketio[2396]: } Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:53:35 ft1905-febf volumio[12426]: info: [pushSourceInfo] {"source":0} Jun 05 17:53:35 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:35 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: pause Jun 05 17:53:35 ft1905-febf volumio[12426]: this.volatileState: {"status":"pause","service":"airplay_emulation","title":"绿色","artist":"陈雪凝","album":"绿色","albumart":"/albumart?cacheid=859&web=%E9%99%88%E9%9B%AA%E5%87%9D/%E7%BB%BF%E8%89%B2/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":113000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:35 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:35 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:35 ft1905-febf socketio[2396]: socket send Jun 05 17:53:35 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:36 ft1905-febf volumio[12426]: this.isVolatile: true, stateService.status: play Jun 05 17:53:36 ft1905-febf volumio[12426]: this.volatileState: {"status":"play","service":"airplay_emulation","title":"绿色","artist":"陈雪凝","album":"绿色","albumart":"/albumart?cacheid=859&web=%E9%99%88%E9%9B%AA%E5%87%9D/%E7%BB%BF%E8%89%B2/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":113000,"duration":297,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":false,"stream":false,"repeatMode":"all"} Jun 05 17:53:36 ft1905-febf volumio[12426]: info: CoreStateMachine::pushState Jun 05 17:53:36 ft1905-febf volumio[12426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 05 17:53:36 ft1905-febf socketio[2396]: socket send Jun 05 17:53:36 ft1905-febf volumio[12426]: SPOTIFY: RECEIVED VOLUMIO VOLUME 43 Jun 05 17:53:36 ft1905-febf volumio[12426]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 17:53:36 ft1905-febf volumio[12426]: { Error: connect ECONNREFUSED 31.13.69.245:443 Jun 05 17:53:36 ft1905-febf volumio[12426]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1107:14) Jun 05 17:53:36 ft1905-febf volumio[12426]: errno: 'ECONNREFUSED', Jun 05 17:53:36 ft1905-febf volumio[12426]: code: 'ECONNREFUSED', Jun 05 17:53:36 ft1905-febf volumio[12426]: syscall: 'connect', Jun 05 17:53:36 ft1905-febf volumio[12426]: address: '31.13.69.245', Jun 05 17:53:36 ft1905-febf volumio[12426]: port: 443 } Jun 05 17:53:36 ft1905-febf volumio[12426]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 05 17:53:37 ft1905-febf sudo[12890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-05 17:52 Jun 05 17:53:37 ft1905-febf sudo[12890]: 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.3.0.152 VOLUMIO_BUILD_DATE=2025-05-26 19:03:27 VOLUMIO_VARIANT=volumio VOLUMIO_HARDWARE=Generic DT based system