-- Logs begin at Mon 2025-01-20 19:33:51 CET, end at Mon 2025-01-20 19:35:53 CET. -- Jan 20 19:34:00 volumio-e-werkstatt kernel: broken atomic modeset userspace detected, disabling atomic Jan 20 19:34:00 volumio-e-werkstatt startx[1215]: (II) modeset(0): Initializing kms color map for depth 24, 8 bpc. Jan 20 19:34:00 volumio-e-werkstatt systemd[1]: soundcard-init.service: Succeeded. Jan 20 19:34:01 volumio-e-werkstatt ntpd[1113]: Listen normally on 3 eth0 192.168.23.20:123 Jan 20 19:34:01 volumio-e-werkstatt ntpd[1113]: new interface(s) found: waking up resolver Jan 20 19:34:01 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:34:01 volumio-e-werkstatt volumio[1214]: info: ----- Volumio3 ---- Jan 20 19:34:01 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:34:01 volumio-e-werkstatt volumio[1214]: info: ----- System startup ---- Jan 20 19:34:01 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:34:02 volumio-e-werkstatt volumio-time-update[865]: volumio-time-update-util: Fetching time from Volumio... Jan 20 19:34:02 volumio-e-werkstatt volumio-time-update[865]: volumio-time-update-util: Setting system time to: 2025-01-20 19:34:55 Jan 20 19:34:03 volumio-e-werkstatt sudo[1438]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-time 2025-01-20 19:34:55 Jan 20 19:34:03 volumio-e-werkstatt sudo[1438]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:03 volumio-e-werkstatt dbus-daemon[854]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.8' (uid=0 pid=1439 comm="timedatectl set-time 2025-01-20 19:34:55 ") Jan 20 19:34:03 volumio-e-werkstatt systemd[1]: Starting Time & Date Service... Jan 20 19:34:03 volumio-e-werkstatt dbus-daemon[854]: [system] Successfully activated service 'org.freedesktop.timedate1' Jan 20 19:34:03 volumio-e-werkstatt systemd[1]: Started Time & Date Service. Jan 20 19:34:55 volumio-e-werkstatt systemd-timedated[1440]: Changed local time to Mon Jan 20 19:34:55 2025 Jan 20 19:34:55 volumio-e-werkstatt sudo[1438]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:55 volumio-e-werkstatt volumio-time-update[865]: volumio-time-update-util: System time updated successfully. Jan 20 19:34:55 volumio-e-werkstatt systemd[1]: Started Volumio Time Update Utility. Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: MYVOLUMIO Environment detected Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Plugin folders cleanup Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning into folder /volumio/app/plugins/ Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category audio_interface Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category miscellanea Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category music_service Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category plugins.json Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category system_controller Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category user_interface Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning into folder /data/plugins/ Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Scanning category music_service Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Plugin folders cleanup completed Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: ----- Core plugins startup ---- Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Loading plugins from folder /volumio/app/plugins/ Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Adding plugin upnp to MyMusic Plugins Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Loading plugins from folder /data/plugins/ Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Loading plugin "system"... Jan 20 19:34:55 volumio-e-werkstatt volumio[1214]: info: Loading plugin "appearance"... Jan 20 19:34:55 volumio-e-werkstatt nmbd[1094]: [2025/01/20 19:34:55.829516, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 20 19:34:55 volumio-e-werkstatt nmbd[1094]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Jan 20 19:34:55 volumio-e-werkstatt systemd[1]: Started Samba NMB Daemon. Jan 20 19:34:55 volumio-e-werkstatt systemd[1]: Starting Samba Winbind Daemon... Jan 20 19:34:56 volumio-e-werkstatt winbindd[1453]: [2025/01/20 19:34:56.041723, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Jan 20 19:34:56 volumio-e-werkstatt winbindd[1453]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Started Samba Winbind Daemon. Jan 20 19:34:56 volumio-e-werkstatt winbindd[1453]: [2025/01/20 19:34:56.049015, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 20 19:34:56 volumio-e-werkstatt winbindd[1453]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Starting Samba SMB Daemon... Jan 20 19:34:56 volumio-e-werkstatt smbd[1458]: [2025/01/20 19:34:56.352855, 0] ../lib/util/become_daemon.c:138(daemon_ready) Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Started Samba SMB Daemon. Jan 20 19:34:56 volumio-e-werkstatt smbd[1458]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Reached target Multi-User System. Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Reached target Graphical Interface. Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Starting Update UTMP about System Runlevel Changes... Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Started Update UTMP about System Runlevel Changes. Jan 20 19:34:56 volumio-e-werkstatt systemd[1]: Startup finished in 5.944s (firmware) + 2.503s (loader) + 7.833s (kernel) + 14.135s (userspace) = 30.416s. Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "network"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Refreshing Cached IP Addresses Jan 20 19:34:56 volumio-e-werkstatt sudo[1468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 19:34:56 volumio-e-werkstatt sudo[1468]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:56 volumio-e-werkstatt sudo[1468]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:56 volumio-e-werkstatt sudo[1470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 19:34:56 volumio-e-werkstatt sudo[1470]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:56 volumio-e-werkstatt sudo[1470]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "services"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "alsa_controller"... Jan 20 19:34:56 volumio-e-werkstatt sudo[1483]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 20 19:34:56 volumio-e-werkstatt sudo[1483]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "wizard"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "networkfs"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Starting Udev Watcher for removable devices Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Ignoring mount for partition: boot Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Ignoring mount for partition: volumio Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Ignoring mount for partition: volumio_data Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "volumio_command_line_client"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Plugin upnp is not enabled Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "my_music"... Jan 20 19:34:56 volumio-e-werkstatt volumio[1214]: info: Loading plugin "mpd"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "upnp_browser"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "alarm-clock"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Plugin airplay_emulation is not enabled Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "last_100"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "webradio"... Jan 20 19:34:57 volumio-e-werkstatt volumio-remote-updater[852]: [2025-01-20 19:34:57] [connect] Successful connection Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "i2s_dacs"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: I2S DAC not set, start Auto-detection Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "volumiodiscovery"... Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** For more information see Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: *** WARNING *** For more information see Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** For more information see Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 20 19:34:57 volumio-e-werkstatt node[1214]: *** WARNING *** For more information see Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Discovery: Started advertising with name: Volumio-e-werkstatt Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Plugin soundcloud is not enabled Jan 20 19:34:57 volumio-e-werkstatt volumio[1214]: info: Loading plugin "spop"... Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: info: Loading plugin "outputs"... Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: info: Loading plugin "albumart"... Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: info: Plugin example_plugin is not enabled Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: info: Loading plugin "inputs"... Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: info: Loading plugin "updater_comm"... Jan 20 19:34:58 volumio-e-werkstatt volumio[1214]: Forking 3 albumart workers Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Plugin mpdemulation is not enabled Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Loading plugin "rest_api"... Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Loading plugin "websocket"... Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Starting Socket.io Server version 2.3.0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Loading i18n strings for locale de Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: Updating browse sources language Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::initPlayerControls Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: Express server listening on port 3000 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: [Metrics] WebUI: 6s 516.28ms Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Setting Device type: x86 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::resetVolumioState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::getcurrentVolume Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioRetrievevolume Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: Starting albumart workers Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: Starting albumart workers Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Completed loading Core Plugins Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: Starting albumart workers Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Preparing to generate the ALSA configuration file Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Volumio Network Manager: Network status updated: 1 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Reading ALSA contributions from plugins. Jan 20 19:34:59 volumio-e-werkstatt volumio-remote-updater[852]: [2025-01-20 19:34:59] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1737398097 101 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::updateTrackBlock Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrackBlock Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioRetrievevolume Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Reloading queue from file Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setRepeat true single undefined Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setRandom null Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Asound.conf file unchanged, so no further update is needed Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Output device has changed, restarting MPD Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: ___________ START PLUGINS ___________ Jan 20 19:34:59 volumio-e-werkstatt sudo[1624]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 20 19:34:59 volumio-e-werkstatt sudo[1624]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::onStart: Initializing MPD Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Creating MPD Configuration file Jan 20 19:34:59 volumio-e-werkstatt sudo[1626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 20 19:34:59 volumio-e-werkstatt sudo[1626]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt sudo[1624]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:59 volumio-e-werkstatt sudo[1630]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 20 19:34:59 volumio-e-werkstatt sudo[1630]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt systemd[1]: Stopping Music Player Daemon... Jan 20 19:34:59 volumio-e-werkstatt sudo[1630]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: [1737398099678] CoreMusicLibrary::Adding element Medienserver Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:34:59 volumio-e-werkstatt sudo[1633]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: [1737398099698] CoreMusicLibrary::Adding element Last_100 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:34:59 volumio-e-werkstatt sudo[1633]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt systemd[1]: mpd.service: Succeeded. Jan 20 19:34:59 volumio-e-werkstatt systemd[1]: Stopped Music Player Daemon. Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: [1737398099700] CoreMusicLibrary::Adding element Webradio Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Initializing BBC Radios Jan 20 19:34:59 volumio-e-werkstatt systemd[1]: Starting Music Player Daemon... Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt sudo[1635]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 20 19:34:59 volumio-e-werkstatt sudo[1635]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt sudo[1635]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Creating Spotify config file Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Volumio Calling Home Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Discovery: adding 1f3fe85d-34da-4b7d-b9c8-17dec5d5e8af Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Discovery: Found device Volumio-e-werkstatt Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: MPD Permissions set Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: MPD Permissions set Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Volumio called home Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: Spotify config file written Jan 20 19:34:59 volumio-e-werkstatt sudo[1676]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 20 19:34:59 volumio-e-werkstatt sudo[1676]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 20 19:34:59 volumio-e-werkstatt systemd[1]: Started go-librespot Daemon. Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt go-librespot[1682]: Librespot-go daemon starting... Jan 20 19:34:59 volumio-e-werkstatt sudo[1676]: pam_unix(sudo:session): session closed for user root Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:34:59 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:35:00 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:00+01:00" level=info msg="generated new device id: 76e8876c6639dc949ef24722cfc45839af5d98da" Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:00 volumio-e-werkstatt mpd[1671]: Jan 20 19:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 20 19:35:00 volumio-e-werkstatt systemd[1]: Started Music Player Daemon. Jan 20 19:35:00 volumio-e-werkstatt sudo[1626]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:00 volumio-e-werkstatt sudo[1633]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:00 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:00+01:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 20 19:35:00 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:00+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 20 19:35:00 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:00+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 20 19:35:00 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:00+01:00" level=debug msg="zeroconf server listening on port 33703" Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: Completed starting Core Plugins Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: ----- MyVolumio plugins startup ---- Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: ------------------------------------------- Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: error: MPD error: The expression evaluated to a falsy value: Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: assert.ok(self.idling) Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: error: The expression evaluated to a falsy value: Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: assert.ok(self.idling) Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: info: MPD running with PID1671 Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: ,establishing connection Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: error: updateQueue error: null Jan 20 19:35:00 volumio-e-werkstatt volumio[1214]: error: updateQueue error: null Jan 20 19:35:01 volumio-e-werkstatt sudo[1483]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:01 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3 Jan 20 19:35:02 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:02 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:02+01:00" level=debug msg="obtained new client token: AAAUJ6a4TUK1zOQQnchDhqlcCudzziYRWdsPz6P1aKGK24WTMUn3IeP7yvqUOrTcYT8km/G1GXtWHgXSq6BX9TdNx3fSGt6zwiCeXP2ZsD0cZ12WP+Vg/HSOTaeCfGARMw8MEKdqCxga2/SJ9OZuDzGjg1PxFFSCh2Q9fv6YLqNgRIOrScGUjtMyR0WuPjEp5yH3euvmDZo0yh6zHPr0obUTZlJ+EDwsWhVrQQJkuOP8EJTLYiDA4BUq7pgn" Jan 20 19:35:02 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:02+01:00" level=debug msg="completed keyexchange" Jan 20 19:35:02 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4 Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="completed challenge" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="authenticated as teamfortress-de" Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: go-librespot daemon successfully initialized Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="authenticated as teamfortress-de" Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="dealer connection opened" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=info msg="accepted zeroconf user teamfortress-de from Timo's schmartphone" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="received connection id: NDA4ZDU2ODQtOTM3ZS00MDg5LWI0NDMtYzBkMDVkNjFlYTM2K2RlYWxlcit0Y3A6Ly8wYWNhNTk2Yi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNjQ3MEMwQUI5M0ZCMEY5QzgzRjI0NEFEMEY2REI5NTg3RDhCNDJERTE0QjZCNTVEOEUyMjU3OTdFQTFCNTI5Qg==" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="put connect state because NEW_DEVICE" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetVisibleSources Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: Listing playlists Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:03 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:03+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=792071&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:03 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:04 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:05 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 20 19:35:05 volumio-e-werkstatt volumio[1214]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 20 19:35:06 volumio-e-werkstatt volumio[1214]: info: Initializing connection to go-librespot Websocket Jan 20 19:35:06 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:06+01:00" level=debug msg="new websocket client" Jan 20 19:35:06 volumio-e-werkstatt volumio[1214]: info: Connection to go-librespot Websocket established Jan 20 19:35:06 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:06+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:07 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:07+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:07 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:07+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=814854&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:08 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:08+01:00" level=debug msg="put connect state inactive" Jan 20 19:35:08 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:08+01:00" level=trace msg="emitting websocket event: inactive" Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: SPOTIFY: received: {"type":"inactive","data":null} Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: error: Failed to decode event: inactive Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin bluetooth to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin multiroom to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin metavolumio to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin cd_controller to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 20 19:35:08 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: Starting MyVolumio Remote Streaming Endpoints Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: MyVolumio login type: Token Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 20 19:35:09 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 20 19:35:09 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:09+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:10 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:10+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:10 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:10+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=163854&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Starting Streaming Service Transparent Proxy Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Streaming services startup Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Starting Streaming Daemon Jan 20 19:35:10 volumio-e-werkstatt sudo[1919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 20 19:35:10 volumio-e-werkstatt sudo[1919]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:10 volumio-e-werkstatt sudo[1919]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Getting Spotify volume Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: error: Cannot start Volumio Streaming Daemon Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Spotify volume: 100 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: SPOTIFY: SPOTIFY VOLUME 100 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: SPOTIFY: VOLUMIO VOLUME 24 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: SPOTIFY: DELTA VOLUME ENOUGH: true Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: info: Setting Spotify Volume from Volumio: 24 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: error: MyVolumio Custom Token format not valid, refreshing it Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: STREAMING PROXY: Starting server on port 3245 Jan 20 19:35:10 volumio-e-werkstatt volumio[1214]: Node JS runtime: 14 Jan 20 19:35:11 volumio-e-werkstatt volumio[1214]: info: MyVolumio login type: Token Jan 20 19:35:11 volumio-e-werkstatt volumio[1214]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: MyVolumio token set successfully Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: MYVOLUMIO: Adding device Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: MYVOLUMIO: Evaluating Server Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: SPOTIFY: SETTING SPOTIFY VOLUME 24 Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Sending Spotify command with payload to local API: /player/volume Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: error: Failed to send command to Spotify local API: /player/volume: Error: Internal Server Error Jan 20 19:35:12 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:12+01:00" level=debug msg="put connect state inactive" Jan 20 19:35:12 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:12+01:00" level=trace msg="emitting websocket event: inactive" Jan 20 19:35:12 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:12+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 20 19:35:12 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:12+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: MyVolumio status changed Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Streaming services startup Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Starting Streaming Daemon Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Removing browser output: myVolumio user plan is not superstar Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Removing audio output: Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Stoppping Tunnel 1 Jan 20 19:35:12 volumio-e-werkstatt sudo[1943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 20 19:35:12 volumio-e-werkstatt sudo[1943]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: SPOTIFY: received: {"type":"inactive","data":null} Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: error: Failed to decode event: inactive Jan 20 19:35:12 volumio-e-werkstatt sudo[1943]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: error: Cannot start Volumio Streaming Daemon Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 20 19:35:12 volumio-e-werkstatt sudo[1946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 20 19:35:12 volumio-e-werkstatt sudo[1946]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:12 volumio-e-werkstatt sudo[1946]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Remote SSH Stopped Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: Setting Geolocation for MyVolumio to eu4 Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:12 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=2143&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: info: Successfully Added MyVolumio device Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: info: Updating MyVolumio device info Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 349" Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=debug msg="put connect state inactive" Jan 20 19:35:13 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:13+01:00" level=trace msg="emitting websocket event: inactive" Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: SPOTIFY: received: {"type":"inactive","data":null} Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: error: Failed to decode event: inactive Jan 20 19:35:13 volumio-e-werkstatt volumio[1214]: info: Successfully Updated MyVolumio device Jan 20 19:35:14 volumio-e-werkstatt systemd[1]: systemd-fsckd.service: Succeeded. Jan 20 19:35:15 volumio-e-werkstatt systemd[1]: systemd-hostnamed.service: Succeeded. Jan 20 19:35:15 volumio-e-werkstatt sudo[1951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 19:35:15 volumio-e-werkstatt sudo[1951]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:15 volumio-e-werkstatt sudo[1951]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:15 volumio-e-werkstatt sudo[1954]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 19:35:15 volumio-e-werkstatt sudo[1954]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:15 volumio-e-werkstatt sudo[1954]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:15 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 192.168.23.20 from 192.168.23.124 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetVisibleSources Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetQueue Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::getQueue Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getQueue Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: Listing playlists Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:16 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPlay Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::play index undefined Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::startPlaybackTimer Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: [1737398117762] ControllerWebradio::clearAddPlayTrack Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand stop Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand stop took 1 milliseconds Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand clear Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand clear took 2 milliseconds Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand load "http://stream.sunshine-live.de/hard/mp3-192/tunein/play.m3u" Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: error: updateQueue error: null Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 4ms Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:17 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand load "http://stream.sunshine-live.de/hard/mp3-192/tunein/play.m3u" took 717 milliseconds Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 716ms Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 714ms Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand play Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 4ms Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand play took 4 milliseconds Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 2ms Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:18 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 13 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 15 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 15 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 6ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 5 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 4 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus stop Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 29ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces system playlist update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Ignoring MPD Status Update Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 12 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 12 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 13 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 8ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 7 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 6ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 4 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":250,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Received an update from plugin. extracting info from payload Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":478,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Received an update from plugin. extracting info from payload Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Received an update from plugin. extracting info from payload Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 90ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 90ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 81ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 65 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 66 milliseconds Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Received an update from plugin. extracting info from payload Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: STATE SERVICE {"status":"play","position":0,"seek":853,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"SUNSHINE LIVE - Hardcore","artist":"SUNSHINE LIVE - Hardcore","album":null,"uri":"http://sunsl.streamabc.net/sunsl-sunslhardcore-mp3-192-4205144?sABC=678r9767%230%239724924o8r6nn4p2pqs41r5ss8ss62p3%23gharva&aw_0_1st.playerid=tunein&amsparams=playerid:tunein;skey:1737398119","trackType":""} Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: verbose: CURRENT POSITION 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState stateService play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::syncState currentStatus play Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: Received an update from plugin. extracting info from payload Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 107ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 106ms Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPlay Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::play index undefined Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:19 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Received Get System Version Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioStop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::stop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::stPlaybackTimer Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::updateTrackBlock Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrackBlock Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::serviceStop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::serviceStop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: [1737398120586] ControllerWebradio::stop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand stop Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand stop took 8 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: ---------------------------- MPD announces state update: player Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::getState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand status Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 4 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 3 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand status took 2 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: sendMpdCommand playlistinfo took 2 milliseconds Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: verbose: ControllerMpd::parseTrackInfo Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ControllerMpd::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::servicePushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::pushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioPushState Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 32ms Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 31ms Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: info: ------------------------------ 30ms Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:20 volumio-e-werkstatt volumio[1214]: SPOTIFY: RECEIVED VOLUMIO VOLUME 24 Jan 20 19:35:24 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:24+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:24 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:24+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:24 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:24+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=696589&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:24 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:24 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Jan 20 19:35:24 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:24 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:25 volumio-e-werkstatt systemd[1]: systemd-timedated.service: Succeeded. Jan 20 19:35:26 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 20 19:35:27 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:27+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:27 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:27+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:27 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:27+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=50218&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:28 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:28+01:00" level=debug msg="put connect state inactive" Jan 20 19:35:28 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:28+01:00" level=trace msg="emitting websocket event: inactive" Jan 20 19:35:28 volumio-e-werkstatt volumio[1214]: SPOTIFY: received: {"type":"inactive","data":null} Jan 20 19:35:28 volumio-e-werkstatt volumio[1214]: error: Failed to decode event: inactive Jan 20 19:35:29 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:29+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetBrowseSources Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:29 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:29+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:29 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:29+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=676699&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:29 volumio-e-werkstatt volumio-remote-updater[852]: No test mode Jan 20 19:35:29 volumio-e-werkstatt volumio-remote-updater[852]: No alpha test mode Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 20 19:35:29 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: Completed starting MyVolumio Plugin Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: [Metrics] CommandRouter: 36s 865.70ms Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumiosetStartupVolume Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::Close All Modals sent Jan 20 19:35:30 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::Close All Modals sent Jan 20 19:35:31 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 20 19:35:31 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 20 19:35:31 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 20 19:35:31 volumio-e-werkstatt volumio[1214]: info: Version has changed, forcing UI Reload Jan 20 19:35:31 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::Reload Ui Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Jan 20 19:35:32 volumio-e-werkstatt sudo[2005]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 20 19:35:32 volumio-e-werkstatt sudo[2005]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:32 volumio-e-werkstatt sudo[2005]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:32 volumio-e-werkstatt sudo[2007]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 20 19:35:32 volumio-e-werkstatt sudo[2007]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 20 19:35:32 volumio-e-werkstatt sudo[2007]: pam_unix(sudo:session): session closed for user root Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetVisibleSources Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: Listing playlists Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 20 19:35:32 volumio-e-werkstatt volumio[1214]: verbose: New Socket.io Connection to 192.168.23.20 from 192.168.23.124 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Jan 20 19:35:32 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:32+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:33 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:33+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:33 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:33+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=90592&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jan 20 19:35:33 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetVisibleSources Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetQueue Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreStateMachine::getQueue Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getQueue Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: Listing playlists Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:34 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:35 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 20 19:35:36 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:36+01:00" level=debug msg="put connect state inactive" Jan 20 19:35:36 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:36+01:00" level=trace msg="emitting websocket event: inactive" Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: SPOTIFY: received: {"type":"inactive","data":null} Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: error: Failed to decode event: inactive Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:36 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:37 volumio-e-werkstatt volumio[1214]: info: BOOT COMPLETED Jan 20 19:35:38 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:38+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:38 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:38+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:38 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:38+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=513719&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:41 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:41+01:00" level=debug msg="handling transfer player command from 582965409ecf463d5f6c3c57d1ce9426f4882291" Jan 20 19:35:42 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:42+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" Jan 20 19:35:42 volumio-e-werkstatt go-librespot[1682]: time="2025-01-20T19:35:42+01:00" level=warning msg="failed handling dealer request" error="failed seeking to track: failed fetching tracks for seek: failed moving to next index 50 (page 1): failed fetching next page: invalid status code from page at radio-apollo/v3/tracks/spotify:station:album:1hOK2ey9W76x9GnftSRgrw?salt=171799&autoplay=false&count=50&isVideo=false&prev_tracks=7GVvj4zJNVuBJSl6StEfn5,2BY7ALEWdloFHgQZG6VMLA,6KEWtSOGKpIXGw6l1uJgsR,54eZmuggBFJbV7k248bTTt,4gRA0i5sxx3jAhHaVjPnUN,1l1YTy9nJ0trwhsCGcimly,5QhikAUv91oMAaFnfKz22u,7DisJ6gAPpdFgMimZjcYxl,0xLrMI4R2xTwRHWV3UQCAZ,5dXED6MP1v1qghkaniirb1,1fMGRxKRtIKNyaMMGrzInM,5GvWrvLIqoHroq7YvO260M,6Wgst4P9SOnc6WGLtfTb1z,3IDc87lrpEHWFBASmgTgFV,2LXISHBkx8FyoxCBkckh19,4IU1RL4BKvFyXtbTwaHAvW,608xszaAxVh4m7NcKJiAbF,1rHvKz5JPpCf9IJDHsyX8P,2yBVeksU2EtrPJbTu4ZslK,41dDygR3r7e926oGUXfrLt,5emxp4RqsF6QoAWXW2Afrk,0I2ELF6uHlL4ABu9aFiou7,2S7hH8gCuwlqL8vqia3eJp,3Um9toULmYFGCpvaIPFw7l,38E7U60ipLSTVDcPIuVzZw,6Qb7gtV6Q4MnUjSbkFcopl,3IvTwPCCjfZczCN2k4qPiH,5jQcJ2st6yHWhUBjoDoZPH,28H3wOEKsaEa8NBEYCLl4j,5OuaAMBmGjjJMK7yXpaFAK,2bS2tETCzUmjALnXEvhOGo,3f0U5NaD1bCk8nmKpn2ZJY,6wP0zUocK5kGLaBYhLbzt5,5qRJD1yaLJ5s0J3JpbgnwA,7zE7VClzAEYa9nUDC950pT,0Jl5bIEve3A4axcjY3EgDZ,4sCCZW0ezEPAexAidFsoVm,3Sm5TYFgMXyXwgAcY2xweX,4IBoDzxcRRRhQ6dozP28aQ,1A7hIo1C8jacIQ5ZiCjc8g,02BsTeJE4q5gWOTt58ur5U,5VSAonaAPhhGn0G7hMYwWK,4mQtXW0vrHC3oTkA1mQsb0,042v1NacbKJzCyi6nBme7T,1x1XQqhBViz4opcpwc7FVs,4ZVZBc5xvMyV3WzWktn8i7,1qjrYozGqc7upUgfN776lZ,2vLaES21zwbX1Rnmj56Bbb,0spSRHFS4zF4Imvz9sJcfL,74t8MRGyoMSIkiN1f43gKc&minimal=true: 502" Jan 20 19:35:42 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 20 19:35:42 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Jan 20 19:35:45 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 19:35:45 volumio-e-werkstatt volumio[1214]: info: Preload queue cleared Jan 20 19:35:46 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 19:35:47 volumio-e-werkstatt volumio[1214]: info: Preload queue cleared Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: Received Get System Version Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:49 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:50 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 5.252.227.76 Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: Received Get System Version Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: Received Get System Info Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: Discovery: Getting this device information Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::volumioGetState Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CorePlayQueue::getTrack 0 Jan 20 19:35:50 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 20 19:35:51 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 19:35:51 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 17.253.14.251 Jan 20 19:35:51 volumio-e-werkstatt volumio[1214]: info: Preload queue cleared Jan 20 19:35:52 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 185.13.148.71 Jan 20 19:35:52 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 5.189.151.39 Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Jan 20 19:35:53 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 62.169.23.198 Jan 20 19:35:53 volumio-e-werkstatt ntpd[1113]: Soliciting pool server 176.9.157.155 Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: TypeError: Cannot read property 'length' of undefined Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at Parser.emit (events.js:400:28) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at IncomingMessage.emit (events.js:412:35) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at endReadableNT (internal/streams/readable.js:1333:12) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Jan 20 19:35:53 volumio-e-werkstatt volumio[1214]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 20 19:35:53 volumio-e-werkstatt sudo[2097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-20 19:34 Jan 20 19:35:53 volumio-e-werkstatt sudo[2097]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"