-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Tue 2025-04-29 23:09:54 CEST. -- Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "network"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Refreshing Cached IP Addresses Apr 29 23:08:01 beolab-8000 sudo[1111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 23:08:01 beolab-8000 sudo[1111]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:01 beolab-8000 sudo[1111]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:01 beolab-8000 sudo[1113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 23:08:01 beolab-8000 sudo[1113]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:01 beolab-8000 sudo[1113]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "services"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "alsa_controller"... Apr 29 23:08:01 beolab-8000 sudo[1122]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 29 23:08:01 beolab-8000 sudo[1122]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "wizard"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "networkfs"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Starting Udev Watcher for removable devices Apr 29 23:08:01 beolab-8000 volumio[957]: info: Ignoring mount for partition: boot Apr 29 23:08:01 beolab-8000 volumio[957]: info: Ignoring mount for partition: volumio Apr 29 23:08:01 beolab-8000 volumio[957]: info: Ignoring mount for partition: volumio_data Apr 29 23:08:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "volumio_command_line_client"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "upnp"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: [1745960881593] Starting Upmpd Daemon Apr 29 23:08:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "my_music"... Apr 29 23:08:01 beolab-8000 volumio[957]: info: Loading plugin "mpd"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "upnp_browser"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "alarm-clock"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "airplay_emulation"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Starting Shairport Sync Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "last_100"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "webradio"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "i2s_dacs"... Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "volumiodiscovery"... Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** For more information see Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 23:08:02 beolab-8000 volumio[957]: *** WARNING *** For more information see Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** For more information see Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 29 23:08:02 beolab-8000 node[957]: *** WARNING *** For more information see Apr 29 23:08:02 beolab-8000 volumio[957]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 29 23:08:02 beolab-8000 volumio[957]: info: Discovery: Started advertising with name: Beolab 8000 Apr 29 23:08:02 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 29 23:08:02 beolab-8000 volumio[957]: info: Loading plugin "spop"... Apr 29 23:08:04 beolab-8000 systemd[1]: systemd-fsckd.service: Succeeded. Apr 29 23:08:04 beolab-8000 volumio[957]: info: Loading plugin "gpio-buttons"... Apr 29 23:08:05 beolab-8000 sudo[1122]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:05 beolab-8000 volumio[957]: info: GPIO-Buttons initialized Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "outputs"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "albumart"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Plugin example_plugin is not enabled Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "inputs"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "updater_comm"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Plugin mpdemulation is not enabled Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "rest_api"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading plugin "websocket"... Apr 29 23:08:05 beolab-8000 volumio[957]: info: Starting Socket.io Server version 2.3.0 Apr 29 23:08:05 beolab-8000 volumio[957]: info: Loading i18n strings for locale nl Apr 29 23:08:05 beolab-8000 volumio[957]: Updating browse sources language Apr 29 23:08:05 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:05 beolab-8000 volumio[957]: Forking 3 albumart workers Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::initPlayerControls Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: Express server listening on port 3000 Apr 29 23:08:06 beolab-8000 volumio[957]: [Metrics] WebUI: 9s 507.81ms Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::resetVolumioState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::getcurrentVolume Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Apr 29 23:08:06 beolab-8000 sh[481]: timed out Apr 29 23:08:06 beolab-8000 dhcpcd[516]: timed out Apr 29 23:08:06 beolab-8000 sh[481]: dhcpcd exited Apr 29 23:08:06 beolab-8000 dhcpcd[516]: dhcpcd exited Apr 29 23:08:06 beolab-8000 sh[481]: ifup: failed to bring up eth0 Apr 29 23:08:06 beolab-8000 systemd[1]: ifup@eth0.service: Main process exited, code=exited, status=1/FAILURE Apr 29 23:08:06 beolab-8000 systemd[1]: ifup@eth0.service: Failed with result 'exit-code'. Apr 29 23:08:06 beolab-8000 volumio[957]: info: Cannot read play queue from file Apr 29 23:08:06 beolab-8000 volumio[957]: info: Volumio Network Manager: Network status updated: 2 Apr 29 23:08:06 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.12 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Apr 29 23:08:06 beolab-8000 volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Apr 29 23:08:06 beolab-8000 volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetVisibleSources Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:06 beolab-8000 volumio[957]: Starting albumart workers Apr 29 23:08:06 beolab-8000 volumio[957]: Starting albumart workers Apr 29 23:08:06 beolab-8000 volumio[957]: Starting albumart workers Apr 29 23:08:06 beolab-8000 volumio[957]: info: VolumeController:: Volume=100 Mute =false Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::updateTrackBlock Apr 29 23:08:06 beolab-8000 volumio[957]: info: CorePlayQueue::getTrackBlock Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::setRepeat null single undefined Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::setRandom false Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:08:06 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:06 beolab-8000 volumio[957]: info: Setting Device type: Raspberry PI Apr 29 23:08:06 beolab-8000 volumio[957]: info: Completed loading Core Plugins Apr 29 23:08:06 beolab-8000 volumio[957]: info: Preparing to generate the ALSA configuration file Apr 29 23:08:07 beolab-8000 volumio[957]: info: VolumeController:: Volume=100 Mute =false Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:07 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:07 beolab-8000 volumio[957]: info: Discovery: adding d781081c-5ad8-452d-8fa3-968ad16c7747 Apr 29 23:08:07 beolab-8000 volumio[957]: info: Discovery: Found device Beolab 8000 Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:07 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:07 beolab-8000 volumio[957]: info: Asound.conf file unchanged, so no further update is needed Apr 29 23:08:07 beolab-8000 volumio[957]: info: Output device has changed, restarting MPD Apr 29 23:08:07 beolab-8000 volumio[957]: info: Output device has changed, restarting Shairport Sync Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:07 beolab-8000 sudo[1183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 29 23:08:07 beolab-8000 sudo[1183]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:07 beolab-8000 sudo[1185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 29 23:08:07 beolab-8000 sudo[1183]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:07 beolab-8000 sudo[1185]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:07 beolab-8000 volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 29 23:08:07 beolab-8000 volumio[957]: info: ___________ START PLUGINS ___________ Apr 29 23:08:07 beolab-8000 systemd[1]: Stopping Music Player Daemon... Apr 29 23:08:07 beolab-8000 volumio[957]: info: ControllerMpd::onStart: Initializing MPD Apr 29 23:08:07 beolab-8000 volumio[957]: info: Creating MPD Configuration file Apr 29 23:08:07 beolab-8000 systemd[1]: mpd.service: Succeeded. Apr 29 23:08:07 beolab-8000 systemd[1]: Stopped Music Player Daemon. Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 23:08:07 beolab-8000 volumio[957]: info: [1745960887452] CoreMusicLibrary::Adding element Media Servers Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:07 beolab-8000 sudo[1214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 29 23:08:07 beolab-8000 sudo[1214]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:07 beolab-8000 systemd[1]: Starting Music Player Daemon... Apr 29 23:08:07 beolab-8000 sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 29 23:08:07 beolab-8000 sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:07 beolab-8000 sudo[1208]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:07 beolab-8000 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Apr 29 23:08:07 beolab-8000 systemd[1]: mpd.service: Succeeded. Apr 29 23:08:07 beolab-8000 systemd[1]: Stopped Music Player Daemon. Apr 29 23:08:07 beolab-8000 systemd[1]: Starting Music Player Daemon... Apr 29 23:08:07 beolab-8000 volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:07 beolab-8000 sudo[1219]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 29 23:08:07 beolab-8000 sudo[1219]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:07 beolab-8000 sudo[1219]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:07 beolab-8000 volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 23:08:07 beolab-8000 volumio[957]: info: [1745960887684] CoreMusicLibrary::Adding element Last_100 Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 23:08:07 beolab-8000 volumio[957]: info: [1745960887687] CoreMusicLibrary::Adding element Webradio Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 23:08:07 beolab-8000 volumio[957]: info: Initializing BBC Radios Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:07 beolab-8000 volumio[957]: info: Creating Spotify config file Apr 29 23:08:07 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:07 beolab-8000 systemd[1]: systemd-hostnamed.service: Succeeded. Apr 29 23:08:07 beolab-8000 volumio[957]: info: GPIO-Buttons: Reading config and creating triggers... Apr 29 23:08:07 beolab-8000 volumio[957]: info: GPIO-Buttons: playPause on pin 536 Apr 29 23:08:07 beolab-8000 volumio[957]: info: Volumio Calling Home Apr 29 23:08:08 beolab-8000 volumio[957]: info: GPIO-Buttons started Apr 29 23:08:08 beolab-8000 volumio[957]: info: MPD Permissions set Apr 29 23:08:08 beolab-8000 volumio[957]: info: MPD Permissions set Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 29 23:08:08 beolab-8000 volumio[957]: info: Discovery: Getting this device information Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:08 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 29 23:08:08 beolab-8000 volumio[957]: info: Volumio called home Apr 29 23:08:08 beolab-8000 volumio[957]: info: Spotify config file written Apr 29 23:08:08 beolab-8000 sudo[1270]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:08 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:08 beolab-8000 sudo[1270]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:08 beolab-8000 volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] CurState: stop PrevState: na Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] CurState: stop PrevState: na Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 systemd[1]: Started go-librespot Daemon. Apr 29 23:08:08 beolab-8000 go-librespot[1272]: go-librespot daemon starting... Apr 29 23:08:08 beolab-8000 sudo[1270]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:08 beolab-8000 volumio[957]: info: No need to fix Spotify hosts Apr 29 23:08:08 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56:3000 from 192.168.2.8 UA: Dart/3.7 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] CurState: stop PrevState: na Apr 29 23:08:08 beolab-8000 volumio[957]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 29 23:08:08 beolab-8000 volumio[957]: info: Starting Shairport Sync Apr 29 23:08:08 beolab-8000 volumio[957]: info: Starting Shairport Sync Apr 29 23:08:08 beolab-8000 volumio[957]: info: Starting Shairport Sync Apr 29 23:08:08 beolab-8000 sudo[1284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 29 23:08:08 beolab-8000 sudo[1284]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:08 beolab-8000 sudo[1286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 29 23:08:08 beolab-8000 volumio[957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 29 23:08:08 beolab-8000 volumio[957]: SPOTIFY: BQBzk9xCSy9wSHDt7KSIMNwDQE_n2D5InMJTb3RTsKHgSB94NQid01k6VaskRiEIgk02g8ULt7BJTUGKDSViWKjolw90riPWPJp-8bcFgTjGd3S0OyLPRe7ER5-UN_DuYfirXNztKoUDiBdD1pqymBZQZcbs10VfS4-w_OIxSeVXjI4oU0m8kbix0cFz6OGj0qcvWLP98WsDt0pW9y1nbD7_-gZxlwcBtp3LBlX_i0l4B6onrAt9CKSy9GJ9cm7HGqe8JRg-yTrais16HYRy5jU Apr 29 23:08:08 beolab-8000 volumio[957]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 29 23:08:08 beolab-8000 sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:08 beolab-8000 volumio[957]: info: New Spotify access token = BQBzk9xCSy9wSHDt7KSIMNwDQE_n2D5InMJTb3RTsKHgSB94NQid01k6VaskRiEIgk02g8ULt7BJTUGKDSViWKjolw90riPWPJp-8bcFgTjGd3S0OyLPRe7ER5-UN_DuYfirXNztKoUDiBdD1pqymBZQZcbs10VfS4-w_OIxSeVXjI4oU0m8kbix0cFz6OGj0qcvWLP98WsDt0pW9y1nbD7_-gZxlwcBtp3LBlX_i0l4B6onrAt9CKSy9GJ9cm7HGqe8JRg-yTrais16HYRy5jU Apr 29 23:08:08 beolab-8000 volumio[957]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 29 23:08:08 beolab-8000 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 29 23:08:08 beolab-8000 systemd[1]: shairport-sync.service: Succeeded. Apr 29 23:08:08 beolab-8000 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 29 23:08:08 beolab-8000 sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 29 23:08:08 beolab-8000 sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:08 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:08 beolab-8000 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 29 23:08:08 beolab-8000 sudo[1284]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:08 beolab-8000 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 29 23:08:08 beolab-8000 volumio[957]: info: Shairport-Sync Started Apr 29 23:08:08 beolab-8000 systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 29 23:08:08 beolab-8000 systemd[1]: shairport-sync.service: Succeeded. Apr 29 23:08:08 beolab-8000 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 29 23:08:08 beolab-8000 volumio[957]: Error adding Membership: Error: addMembership EINVAL Apr 29 23:08:08 beolab-8000 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 29 23:08:08 beolab-8000 sudo[1286]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:08 beolab-8000 sudo[1293]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:08 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 29 23:08:08 beolab-8000 volumio[957]: info: Shairport-Sync Started Apr 29 23:08:08 beolab-8000 volumio[957]: info: Shairport-Sync Started Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 29 23:08:08 beolab-8000 volumio[957]: info: Discovery: Getting this device information Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:08 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 29 23:08:08 beolab-8000 volumio[957]: SPOTIFY: User informations: {"country":"NL","display_name":"Jan Karssies","email":"hjkarssies@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/hjkarssies"},"followers":{"href":null,"total":20},"href":"https://api.spotify.com/v1/users/hjkarssies","id":"hjkarssies","images":[{"height":300,"url":"https://scontent-lhr6-1.xx.fbcdn.net/v/t39.30808-1/470205093_10169792480825425_5520654221226756317_n.jpg?stp=c0.132.1363.1363a_dst-jpg_s320x320_tt6&_nc_cat=102&ccb=1-7&_nc_sid=79bf43&_nc_ohc=9J5TFW5rnSsQ7kNvwFSgSZ5&_nc_oc=Adk6jX0vq1Bx_dE_Xl2t2suy8cXvR8c0tmjt3nsxkXtVsE_Rh1nQ4wWt7y-rTS8eHYrs4UjwS5i76dpq2hRaNt0b&_nc_zt=24&_nc_ht=scontent-lhr6-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MTfHpnDo-jvJMF4gVDI91Q&oh=00_AfHi_8zMH3htr33cU060ZDUhrO8EneMChPGqvzRheeW9ZQ&oe=6817141B","width":300},{"height":64,"url":"https://scontent-lhr6-1.xx.fbcdn.net/v/t39.30808-1/470205093_10169792480825425_5520654221226756317_n.jpg?stp=c0.132.1363.1363a_cp0_dst-jpg_s50x50_tt6&_nc_cat=102&ccb=1-7&_nc_sid=fe756c&_nc_ohc=9J5TFW5rnSsQ7kNvwFSgSZ5&_nc_oc=Adk6jX0vq1Bx_dE_Xl2t2suy8cXvR8c0tmjt3nsxkXtVsE_Rh1nQ4wWt7y-rTS8eHYrs4UjwS5i76dpq2hRaNt0b&_nc_zt=24&_nc_ht=scontent-lhr6-1.xx&edm=AP4hL3IEAAAA&_nc_gid=MTfHpnDo-jvJMF4gVDI91Q&oh=00_AfF9SQLPHaiod318K6BQQOQ38nImjZtepavEzOALhh6u8g&oe=6817141B","width":64}],"product":"premium","type":"user","uri":"spotify:user:hjkarssies"} Apr 29 23:08:08 beolab-8000 volumio[957]: info: Spotify Successfully logged in Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 29 23:08:08 beolab-8000 volumio[957]: info: [1745960888809] CoreMusicLibrary::Adding element Spotify Apr 29 23:08:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:08 beolab-8000 volumio[957]: Cannot find translation for source Spotify Apr 29 23:08:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:08+02:00" level=info msg="running go-librespot 0.2.0" Apr 29 23:08:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:08+02:00" level=debug msg="app state loaded" Apr 29 23:08:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:08+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 29 23:08:09 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:09 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:09 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: OFF Apr 29 23:08:09 beolab-8000 mpd[1242]: Apr 29 23:08 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 29 23:08:09 beolab-8000 systemd[1]: Started Music Player Daemon. Apr 29 23:08:09 beolab-8000 sudo[1185]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:09 beolab-8000 sudo[1214]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:09 beolab-8000 volumio[957]: info: Completed starting Core Plugins Apr 29 23:08:09 beolab-8000 volumio[957]: info: ------------------------------------------- Apr 29 23:08:09 beolab-8000 volumio[957]: info: ----- MyVolumio plugins startup ---- Apr 29 23:08:09 beolab-8000 volumio[957]: info: ------------------------------------------- Apr 29 23:08:09 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 29 23:08:09 beolab-8000 volumio[957]: error: MPD error: The expression evaluated to a falsy value: Apr 29 23:08:09 beolab-8000 volumio[957]: assert.ok(self.idling) Apr 29 23:08:09 beolab-8000 volumio[957]: error: The expression evaluated to a falsy value: Apr 29 23:08:09 beolab-8000 volumio[957]: assert.ok(self.idling) Apr 29 23:08:09 beolab-8000 volumio[957]: info: MPD running with PID1242 Apr 29 23:08:09 beolab-8000 volumio[957]: ,establishing connection Apr 29 23:08:09 beolab-8000 volumio[957]: error: updateQueue error: null Apr 29 23:08:09 beolab-8000 volumio[957]: error: updateQueue error: null Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=info msg="zeroconf server listening on port 41119" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="obtained new client token: AADIu58BJEPYImQe2QBxnLLlYd2NWKSEA/pVinssFD61rzM1TjB2xnpMI2XrCf55++zeQXGyfRA1ctktOQB3y79gzHqLDPLaPhuROX0nRmdi+MV/BdoMGaUeZP/gj/YES8poZNX+vPCmiFob/iVyVcTEpk5OlLM1h0s2ACP1BxjoQxwUA1OHNgRhTO2sMst4bEHe26sHCt4muGhG/MvngUNiZt5Kl0dDJ3Ef9EcL+1MF7fsNCHvPEVY=" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="completed keyexchange" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="completed challenge" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=info msg="authenticated AP as hjkarssies" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=info msg="authenticated Login5 as hjkarssies" Apr 29 23:08:10 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:10+02:00" level=debug msg="initializing zeroconf session, username: hjkarssies" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="dealer connection opened" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=trace msg="starting accesspoint recv loop" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=trace msg="starting dealer recv loop" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=trace msg="received accesspoint ping" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="received connection id: ZWQ1N2U1NDEtNmM2OS00MzM5LWFjZjktNWVjYzliZTkxMGJlK2RlYWxlcit0Y3A6Ly8wYWNhNTkzMS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOEYxNTM5QTg0NUM1MDhCOEVBQkQ3QTEzRUJCQTU0QzAzMDYyNURENzk3QjQ3QjM0RDRFNjlFOEY3N0U0QjQ0Nw==" Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=trace msg="received accesspoint pong ack" Apr 29 23:08:11 beolab-8000 sudo[1308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 23:08:11 beolab-8000 sudo[1308]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:11 beolab-8000 sudo[1308]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:11 beolab-8000 sudo[1310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 23:08:11 beolab-8000 sudo[1310]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:11 beolab-8000 sudo[1310]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:11+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 29 23:08:11 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.8 UA: Mozilla/5.0 (Linux; Android 15; CPH2493 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Apr 29 23:08:11 beolab-8000 volumio[957]: info: go-librespot daemon successfully initialized Apr 29 23:08:11 beolab-8000 sudo[1328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 23:08:11 beolab-8000 sudo[1328]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:11 beolab-8000 sudo[1328]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:11 beolab-8000 sudo[1330]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 23:08:11 beolab-8000 sudo[1330]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:11 beolab-8000 sudo[1330]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:11 beolab-8000 sudo[1334]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 29 23:08:11 beolab-8000 sudo[1334]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:11 beolab-8000 systemd[1]: Started UPnP Renderer front-end to MPD. Apr 29 23:08:11 beolab-8000 sudo[1334]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:11 beolab-8000 volumio[957]: info: Upmpdcli Daemon Started Apr 29 23:08:11 beolab-8000 volumio[1336]: Generating RSA private key, 4096 bit long modulus (2 primes) Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetVisibleSources Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:12 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 29 23:08:12 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 29 23:08:12 beolab-8000 sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 29 23:08:12 beolab-8000 sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:12 beolab-8000 sudo[1353]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:12 beolab-8000 sudo[1355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 29 23:08:12 beolab-8000 sudo[1355]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:12 beolab-8000 sudo[1355]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:13 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.8 UA: Mozilla/5.0 (Linux; Android 15; CPH2493 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:13 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:13 beolab-8000 volumio[957]: 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: 8 Apr 29 23:08:13 beolab-8000 volumio-remote-updater[559]: [2025-04-29 23:08:13] [connect] Successful connection Apr 29 23:08:13 beolab-8000 volumio-remote-updater[559]: [2025-04-29 23:08:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1745960893 101 Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 29 23:08:13 beolab-8000 volumio[957]: info: Listing playlists Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Apr 29 23:08:13 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 29 23:08:14 beolab-8000 volumio[957]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 29 23:08:14 beolab-8000 volumio[957]: info: Initializing connection to go-librespot Websocket Apr 29 23:08:14 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:14+02:00" level=debug msg="new websocket client" Apr 29 23:08:14 beolab-8000 volumio[957]: info: Connection to go-librespot Websocket established Apr 29 23:08:16 beolab-8000 volumio[1336]: ..........................................++++ Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="handling transfer player command from 6f5c6e580f70ac6059c59a68c520a14227b2eae0" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="resolved context of track" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 0 with 10 items (list: 10)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 1 with 11 items (list: 21)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 2 with 3 items (list: 24)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 3 with 2 items (list: 26)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 volumio[957]: info: Getting Spotify volume Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 4 with 1 items (list: 27)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 5 with 5 items (list: 32)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:17 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:17 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 29 23:08:17 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME undefined Apr 29 23:08:17 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 100 Apr 29 23:08:17 beolab-8000 volumio[957]: info: Aligning Spotify Volume to Volumio Volume Apr 29 23:08:17 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:17 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:17 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 100 Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 6 with 1 items (list: 33)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 7 with 1 items (list: 34)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 8 with 1 items (list: 35)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 9 with 1 items (list: 36)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 10 with 1 items (list: 37)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page from (has next: false)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="fetched new page 11 with 1 items (list: 38)" uri="spotify:artist:3k3RY7kR8f0vp8Cq27P141" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="loading track (paused: false, position: 93765ms)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=trace msg="emitting websocket event: will_play" Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin bluetooth to MyMusic Plugins Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin multiroom to MyMusic Plugins Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin metavolumio to MyMusic Plugins Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin cd_controller to MyMusic Plugins Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="selected format OGG_VORBIS_320 (ded50e939dde9b16eb50141fa8e274f24c5dccab)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="requested aes key for file ded50e939dde9b16eb50141fa8e274f24c5dccab, gid: 4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 29 23:08:17 beolab-8000 volumio[957]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 29 23:08:17 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 29 23:08:17 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:17+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 3260" Apr 29 23:08:18 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:18+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2076" Apr 29 23:08:18 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:18+02:00" level=debug msg="fetched first chunk of 18, total size is 9059909 bytes" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 29 23:08:19 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 29 23:08:19 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:19 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:19 beolab-8000 volumio[957]: info: Starting MyVolumio Remote Streaming Endpoints Apr 29 23:08:19 beolab-8000 volumio[957]: info: MyVolumio login type: Token Apr 29 23:08:19 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 29 23:08:19 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 9/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 6/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=trace msg="seek to 93765ms (diff: 57ms, samples: 4135036, bytes: 3660786)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="created new output device" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=info msg="loaded track \"wash my sins away\" (paused: false, position: 93765ms, duration: 232500ms, prefetched: false)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:08:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:19+02:00" level=debug msg="fetched chunk 8/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="fetched chunk 7/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=trace msg="scheduling prefetch in 109s" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=trace msg="emitting websocket event: metadata" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=trace msg="emitting websocket event: active" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="sending successful reply for dealer request" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=trace msg="emitting websocket event: playing" Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="fetched chunk 10/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:08:20 beolab-8000 volumio[957]: info: Starting Streaming Service Transparent Proxy Apr 29 23:08:20 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 29 23:08:20 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 29 23:08:20 beolab-8000 volumio[957]: info: Streaming services startup Apr 29 23:08:20 beolab-8000 volumio[957]: info: Starting Streaming Daemon Apr 29 23:08:20 beolab-8000 sudo[1368]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 29 23:08:20 beolab-8000 sudo[1368]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:20 beolab-8000 volumio[957]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 29 23:08:20 beolab-8000 sudo[1368]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 29 23:08:20 beolab-8000 volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","name":"wash my sins away","artist_names":["berlioz"],"album_name":"wash my sins away","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","position":93765,"duration":232500,"release_date":"year:2023 month:5 day:12","track_number":1,"disc_number":1}} Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"active","data":null} Apr 29 23:08:20 beolab-8000 volumio[957]: info: Aligning Spotify Volume to Volumio Volume Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:20 beolab-8000 volumio[957]: info: CorePlayQueue::getTrack 0 Apr 29 23:08:20 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 100 Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:08:20 beolab-8000 volumio[957]: info: Spotify is playing in volatile mode Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: UNSET VOLATILE Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"random":false,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:08:20 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:20 beolab-8000 volumio[957]: info: Spotify volume: 100 Apr 29 23:08:20 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:20+02:00" level=debug msg="update volume to 65535/65535" Apr 29 23:08:20 beolab-8000 volumio[957]: error: Cannot start Volumio Streaming Daemon Apr 29 23:08:20 beolab-8000 volumio[957]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 29 23:08:20 beolab-8000 volumio[957]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 29 23:08:20 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: stop Apr 29 23:08:20 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: ON Apr 29 23:08:20 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: play Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="handling pause player command from 6f5c6e580f70ac6059c59a68c520a14227b2eae0" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="pause track at 95018ms" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="sending successful reply for dealer request" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=trace msg="emitting websocket event: paused" Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: {"status":"pause","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:08:21 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:21 beolab-8000 volumio[957]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 29 23:08:21 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: play Apr 29 23:08:21 beolab-8000 volumio[957]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 29 23:08:21 beolab-8000 volumio[957]: STREAMING PROXY: Starting server on port 3245 Apr 29 23:08:21 beolab-8000 volumio[957]: Node JS runtime: 14 Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 29 23:08:21 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:21+02:00" level=trace msg="emitting websocket event: volume" Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 29 23:08:21 beolab-8000 volumio[957]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 29 23:08:22 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: OFF Apr 29 23:08:22 beolab-8000 volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 29 23:08:22 beolab-8000 volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Apr 29 23:08:22 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:22+02:00" level=debug msg="update volume to 65535/65535" Apr 29 23:08:23 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:23+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 29 23:08:23 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:23+02:00" level=trace msg="emitting websocket event: volume" Apr 29 23:08:23 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} Apr 29 23:08:23 beolab-8000 volumio[957]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 Apr 29 23:08:23 beolab-8000 volumio[957]: info: MyVolumio token set successfully Apr 29 23:08:23 beolab-8000 volumio[957]: info: MYVOLUMIO: Adding device Apr 29 23:08:23 beolab-8000 volumio[957]: info: MYVOLUMIO: Evaluating Server Apr 29 23:08:23 beolab-8000 volumio[957]: info: MyVolumio status changed Apr 29 23:08:23 beolab-8000 volumio[957]: info: Streaming services startup Apr 29 23:08:23 beolab-8000 volumio[957]: info: Starting Streaming Daemon Apr 29 23:08:23 beolab-8000 volumio[957]: info: Removing browser output: myVolumio user plan is not superstar Apr 29 23:08:23 beolab-8000 volumio[957]: info: Removing audio output: Apr 29 23:08:23 beolab-8000 volumio[957]: info: Stoppping Tunnel 1 Apr 29 23:08:23 beolab-8000 sudo[1410]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 29 23:08:23 beolab-8000 sudo[1410]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:23 beolab-8000 sudo[1412]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 29 23:08:23 beolab-8000 sudo[1412]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 29 23:08:23 beolab-8000 sudo[1412]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:23 beolab-8000 volumio[957]: info: Remote SSH Stopped Apr 29 23:08:23 beolab-8000 sudo[1410]: pam_unix(sudo:session): session closed for user root Apr 29 23:08:23 beolab-8000 volumio[957]: error: Cannot start Volumio Streaming Daemon Apr 29 23:08:23 beolab-8000 volumio[957]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 29 23:08:23 beolab-8000 volumio[957]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 29 23:08:24 beolab-8000 volumio[957]: info: Setting Geolocation for MyVolumio to eu8 Apr 29 23:08:24 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:24 beolab-8000 volumio[957]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 29 23:08:24 beolab-8000 volumio[1336]: ................................................................++++ Apr 29 23:08:24 beolab-8000 volumio[1336]: e is 65537 (0x010001) Apr 29 23:08:24 beolab-8000 volumio[1336]: writing RSA key Apr 29 23:08:25 beolab-8000 volumio[957]: info: Updating MyVolumio device info Apr 29 23:08:25 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:25 beolab-8000 volumio[957]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 29 23:08:27 beolab-8000 systemd[1]: systemd-timedated.service: Succeeded. Apr 29 23:08:28 beolab-8000 volumio[957]: info: MYVOLUMIO: Adding device Apr 29 23:08:28 beolab-8000 volumio[957]: info: MYVOLUMIO: Evaluating Server Apr 29 23:08:29 beolab-8000 volumio[957]: info: Setting Geolocation for MyVolumio to eu9 Apr 29 23:08:29 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:29 beolab-8000 volumio[957]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 29 23:08:29 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.8 UA: Mozilla/5.0 (Linux; Android 15; CPH2493 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Apr 29 23:08:30 beolab-8000 volumio[957]: info: Updating MyVolumio device info Apr 29 23:08:30 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:30 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:30 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:30 beolab-8000 volumio[957]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 29 23:08:34 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 29 23:08:34 beolab-8000 volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Apr 29 23:08:34 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:34 beolab-8000 volumio[957]: verbose: New Socket.io Connection to 192.168.2.56 from 192.168.2.8 UA: Mozilla/5.0 (Linux; Android 15; CPH2493 Build/AP3A.240617.008; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Apr 29 23:08:34 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:34 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 29 23:08:34 beolab-8000 volumio[957]: info: Listing playlists Apr 29 23:08:35 beolab-8000 volumiologrotate[567]: ls: cannot access '/var/log/samba/log.wb-BEOLAB': No such file or directory Apr 29 23:08:35 beolab-8000 volumiologrotate[567]: ls: cannot access '8000': No such file or directory Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetVisibleSources Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetQueue Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreStateMachine::getQueue Apr 29 23:08:37 beolab-8000 volumio[957]: info: CorePlayQueue::getQueue Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 29 23:08:38 beolab-8000 volumio-remote-updater[559]: No test mode Apr 29 23:08:38 beolab-8000 volumio-remote-updater[559]: No alpha test mode Apr 29 23:08:38 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 29 23:08:38 beolab-8000 volumio[957]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Apr 29 23:08:38 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetBrowseSources Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 29 23:08:39 beolab-8000 volumio[957]: info: Received Get System Info Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 29 23:08:39 beolab-8000 volumio[957]: info: Discovery: Getting this device information Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:39 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 29 23:08:40 beolab-8000 volumio[957]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 29 23:08:40 beolab-8000 volumio[957]: info: Completed starting MyVolumio Plugin Apr 29 23:08:40 beolab-8000 volumio[957]: [Metrics] CommandRouter: 43s 179.36ms Apr 29 23:08:40 beolab-8000 volumio[957]: info: CoreCommandRouter::volumiosetStartupVolume Apr 29 23:08:40 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 29 23:08:40 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:40 beolab-8000 volumio[957]: info: CoreCommandRouter::Close All Modals sent Apr 29 23:08:40 beolab-8000 volumio[957]: info: CoreCommandRouter::Close All Modals sent Apr 29 23:08:41 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:41+02:00" level=trace msg="sent dealer ping" Apr 29 23:08:41 beolab-8000 go-librespot[1272]: time="2025-04-29T23:08:41+02:00" level=trace msg="received dealer pong" Apr 29 23:08:41 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 29 23:08:41 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 29 23:08:41 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 29 23:08:41 beolab-8000 ntpd[718]: Soliciting pool server 178.239.19.63 Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 29 23:08:42 beolab-8000 volumio[957]: info: Getting Alsa Cards List without I2S DAC Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 29 23:08:42 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 29 23:08:42 beolab-8000 ntpd[718]: Soliciting pool server 178.215.228.24 Apr 29 23:08:43 beolab-8000 ntpd[718]: Soliciting pool server 45.138.55.62 Apr 29 23:08:43 beolab-8000 ntpd[718]: Soliciting pool server 193.123.56.220 Apr 29 23:08:44 beolab-8000 ntpd[718]: Soliciting pool server 178.239.19.61 Apr 29 23:08:44 beolab-8000 ntpd[718]: Soliciting pool server 45.83.205.227 Apr 29 23:08:44 beolab-8000 ntpd[718]: Soliciting pool server 162.159.200.123 Apr 29 23:08:45 beolab-8000 ntpd[718]: Soliciting pool server 81.172.248.188 Apr 29 23:08:45 beolab-8000 ntpd[718]: Soliciting pool server 178.239.19.58 Apr 29 23:08:45 beolab-8000 ntpd[718]: Soliciting pool server 195.35.113.80 Apr 29 23:08:45 beolab-8000 ntpd[718]: Soliciting pool server 185.51.192.63 Apr 29 23:08:46 beolab-8000 ntpd[718]: Soliciting pool server 94.198.159.11 Apr 29 23:08:46 beolab-8000 ntpd[718]: Soliciting pool server 185.45.112.121 Apr 29 23:08:46 beolab-8000 ntpd[718]: Soliciting pool server 94.198.159.15 Apr 29 23:08:46 beolab-8000 ntpd[718]: Soliciting pool server 162.159.200.1 Apr 29 23:08:47 beolab-8000 volumio[957]: info: BOOT COMPLETED Apr 29 23:08:47 beolab-8000 ntpd[718]: Soliciting pool server 23.94.217.117 Apr 29 23:08:47 beolab-8000 ntpd[718]: Soliciting pool server 45.138.55.61 Apr 29 23:08:47 beolab-8000 ntpd[718]: Soliciting pool server 5.255.124.190 Apr 29 23:08:47 beolab-8000 ntpd[718]: Soliciting pool server 178.239.19.59 Apr 29 23:08:50 beolab-8000 ntpd[718]: receive: Unexpected origin timestamp 0xebbbbe61.e90eebc9 does not match aorg 0000000000.00000000 from server@195.35.113.80 xmt 0xebbbbe62.76c170f7 Apr 29 23:08:57 beolab-8000 volumio[957]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioGetState Apr 29 23:08:57 beolab-8000 volumio[957]: info: Restoring Previous Volume level: 100 false false Apr 29 23:08:57 beolab-8000 volumio[957]: info: Volume configurations have been set Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 29 23:08:57 beolab-8000 volumio[957]: info: Updating Volume Controller Parameters: Device: 2 Name: HiFiBerry DAC Plus Mixer: Digital Max Vol: 50 Vol Curve; logarithmic Vol Steps: 1 Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 29 23:08:57 beolab-8000 volumio[957]: info: Disabling external Volume Control Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 29 23:08:57 beolab-8000 volumio[957]: info: Getting Alsa Cards List without I2S DAC Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 29 23:08:57 beolab-8000 volumio[957]: info: VolumeController:: Volume=100 Mute =false Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:08:57 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:08:57 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:08:57 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 29 23:09:01 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume50 Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 100 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 50 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:01 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 50 Apr 29 23:09:01 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume25 Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 50 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 25 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:01 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 25 Apr 29 23:09:01 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume100 Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:01 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:01 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 25 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 50 Apr 29 23:09:01 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:01 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 50 Apr 29 23:09:02 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioVolatilePlay Apr 29 23:09:02 beolab-8000 volumio[957]: info: CoreStateMachine::volatilePlay Apr 29 23:09:02 beolab-8000 volumio[957]: info: Spotify Play Apr 29 23:09:02 beolab-8000 volumio[957]: info: Sending Spotify command to local API: /player/resume Apr 29 23:09:02 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:02+02:00" level=trace msg="seek to 95018ms (diff: 46ms, samples: 4190293, bytes: 3712392)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:09:02 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:02+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Apr 29 23:09:02 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:02+02:00" level=debug msg="resume track at 94672ms" Apr 29 23:09:02 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:02+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:02 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:02+02:00" level=trace msg="scheduling prefetch in 108s" Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=trace msg="emitting websocket event: playing" Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: pause Apr 29 23:09:03 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: ON Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 50 Apr 29 23:09:03 beolab-8000 volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Apr 29 23:09:03 beolab-8000 volumio[957]: error: Failed to send command to Spotify local API: /player/volume: Error: Bad Request Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: play Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPause Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::pause Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::stPlaybackTimer Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::servicePause Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePause Apr 29 23:09:03 beolab-8000 volumio[957]: info: Spotify Received pause Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY PAUSE Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","codec":"ogg","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":"50","dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Apr 29 23:09:03 beolab-8000 volumio[957]: info: Sending Spotify command to local API: /player/pause Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=debug msg="pause track at 95681ms" Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:03 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:03+02:00" level=trace msg="emitting websocket event: paused" Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: {"status":"pause","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:03 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:03 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: play Apr 29 23:09:03 beolab-8000 volumio[957]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Apr 29 23:09:03 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Apr 29 23:09:04 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: OFF Apr 29 23:09:05 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume40 Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 50 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 40 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:05 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 40 Apr 29 23:09:05 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume25 Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 40 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 25 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:05 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 25 Apr 29 23:09:05 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume20 Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:05 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:05 beolab-8000 volumio[957]: info: [ASDebug] CurState: pause PrevState: pause Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 25 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 20 Apr 29 23:09:05 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:05 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 20 Apr 29 23:09:07 beolab-8000 volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 20 Apr 29 23:09:07 beolab-8000 volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Apr 29 23:09:07 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:07+02:00" level=debug msg="update volume to 13107/65535" Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioVolatilePlay Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreStateMachine::volatilePlay Apr 29 23:09:08 beolab-8000 volumio[957]: info: Spotify Play Apr 29 23:09:08 beolab-8000 volumio[957]: info: Sending Spotify command to local API: /player/resume Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=trace msg="seek to 95681ms (diff: 88ms, samples: 4219532, bytes: 3739699)" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 100000 us, period size = 4410 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 5 frames" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=debug msg="resume track at 95593ms" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=trace msg="scheduling prefetch in 107s" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=trace msg="emitting websocket event: playing" Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","play_origin":"free-tier-artist"}} Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: pause Apr 29 23:09:08 beolab-8000 volumio[957]: info: [ASDebug] Togle GPIO: ON Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 29 23:09:08 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:08+02:00" level=trace msg="emitting websocket event: volume" Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"volume","data":{"value":20,"max":100}} Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: RECEIVED SPOTIFY VOLUME 20 Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: PUSH STATE SPOTIFY Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: {"status":"play","service":"spop","title":"wash my sins away","artist":"berlioz","album":"wash my sins away","albumart":"https://i.scdn.co/image/ab67616d00001e02af5745dba0453e9453801f79","uri":"spotify:track:4narDGRW69BFMIPpgCrh6b","trackType":"spotify","seek":93765,"duration":232,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::servicePushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:08 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: play Apr 29 23:09:08 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Apr 29 23:09:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:11+02:00" level=trace msg="sent dealer ping" Apr 29 23:09:11 beolab-8000 volumio[957]: info: VolumeController::SetAlsaVolume10 Apr 29 23:09:11 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:11+02:00" level=trace msg="received dealer pong" Apr 29 23:09:11 beolab-8000 volumio[957]: info: CoreStateMachine::pushState Apr 29 23:09:11 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 29 23:09:11 beolab-8000 volumio[957]: info: CoreCommandRouter::volumioPushState Apr 29 23:09:11 beolab-8000 volumio[957]: info: [ASDebug] CurState: play PrevState: play Apr 29 23:09:11 beolab-8000 volumio[957]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Apr 29 23:09:11 beolab-8000 volumio[957]: SPOTIFY: SPOTIFY VOLUME 20 Apr 29 23:09:11 beolab-8000 volumio[957]: SPOTIFY: VOLUMIO VOLUME 10 Apr 29 23:09:11 beolab-8000 volumio[957]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 29 23:09:11 beolab-8000 volumio[957]: info: Setting Spotify Volume from Volumio: 10 Apr 29 23:09:13 beolab-8000 volumio[957]: SPOTIFY: SETTING SPOTIFY VOLUME 10 Apr 29 23:09:13 beolab-8000 volumio[957]: info: Sending Spotify command with payload to local API: /player/volume Apr 29 23:09:13 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:13+02:00" level=debug msg="update volume to 6553/65535" Apr 29 23:09:14 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:14+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 29 23:09:14 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:14+02:00" level=trace msg="emitting websocket event: volume" Apr 29 23:09:14 beolab-8000 volumio[957]: SPOTIFY: received: {"type":"volume","data":{"value":10,"max":100}} Apr 29 23:09:14 beolab-8000 volumio[957]: SPOTIFY: RECEIVED SPOTIFY VOLUME 10 Apr 29 23:09:19 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:19+02:00" level=debug msg="fetched chunk 11/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 29 23:09:23 beolab-8000 volumio[957]: info: Getting Alsa Cards List without I2S DAC Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Apr 29 23:09:23 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Apr 29 23:09:32 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:32+02:00" level=debug msg="fetched chunk 12/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:09:36 beolab-8000 volumiologrotate[567]: ls: cannot access '/var/log/samba/log.wb-BEOLAB': No such file or directory Apr 29 23:09:36 beolab-8000 volumiologrotate[567]: ls: cannot access '8000': No such file or directory Apr 29 23:09:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 29 23:09:37 beolab-8000 volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 29 23:09:41 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:41+02:00" level=trace msg="sent dealer ping" Apr 29 23:09:41 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:41+02:00" level=trace msg="received dealer pong" Apr 29 23:09:41 beolab-8000 volumio[957]: info: Starting Uninstall of plugin system_controller - ampswitch Apr 29 23:09:41 beolab-8000 volumio[957]: info: Uninstalling plugin ampswitch Apr 29 23:09:41 beolab-8000 volumio[957]: info: [ASDebug] Port: 12 Apr 29 23:09:41 beolab-8000 volumio[957]: info: [ASDebug] Inverted: false Apr 29 23:09:41 beolab-8000 volumio[957]: info: [ASDebug] Delay: 720 Apr 29 23:09:45 beolab-8000 go-librespot[1272]: time="2025-04-29T23:09:45+02:00" level=debug msg="fetched chunk 13/17, size: 524288" uri="spotify:track:4narDGRW69BFMIPpgCrh6b" Apr 29 23:09:54 beolab-8000 volumio[957]: info: Starting Uninstall of plugin system_controller - ampswitch Apr 29 23:09:54 beolab-8000 volumio[957]: info: Uninstalling plugin ampswitch Apr 29 23:09:54 beolab-8000 volumio[957]: info: [ASDebug] Port: 12 Apr 29 23:09:54 beolab-8000 volumio[957]: info: [ASDebug] Inverted: false Apr 29 23:09:54 beolab-8000 volumio[957]: info: [ASDebug] Delay: 720 Apr 29 23:09:54 beolab-8000 volumio[957]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 23:09:54 beolab-8000 volumio[957]: Error: EBADF: bad file descriptor, close Apr 29 23:09:54 beolab-8000 volumio[957]: at Object.closeSync (fs.js:439:3) Apr 29 23:09:54 beolab-8000 volumio[957]: at Object.closeSync (/volumio/node_modules/graceful-fs/graceful-fs.js:74:20) Apr 29 23:09:54 beolab-8000 volumio[957]: at Object. (/data/plugins/system_controller/ampswitch/node_modules/graceful-fs/graceful-fs.js:51:27) Apr 29 23:09:54 beolab-8000 volumio[957]: at Object.closeSync (/data/plugins/system_hardware/gpio-buttons/node_modules/graceful-fs/graceful-fs.js:51:27) Apr 29 23:09:54 beolab-8000 volumio[957]: at Gpio.unexport (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:307:8) Apr 29 23:09:54 beolab-8000 volumio[957]: at AmpSwitchController.freeGPIO (/data/plugins/system_controller/ampswitch/index.js:242:19) Apr 29 23:09:54 beolab-8000 volumio[957]: at AmpSwitchController.onStop (/data/plugins/system_controller/ampswitch/index.js:90:10) Apr 29 23:09:54 beolab-8000 volumio[957]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Apr 29 23:09:54 beolab-8000 volumio[957]: at PluginManager.unInstallPlugin (/volumio/app/pluginmanager.js:1449:10) Apr 29 23:09:54 beolab-8000 volumio[957]: at CoreCommandRouter.unInstallPlugin (/volumio/app/index.js:1484:22) Apr 29 23:09:54 beolab-8000 volumio[957]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1260:45) Apr 29 23:09:54 beolab-8000 volumio[957]: at Socket.emit (events.js:315:20) Apr 29 23:09:54 beolab-8000 volumio[957]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 29 23:09:54 beolab-8000 volumio[957]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Apr 29 23:09:54 beolab-8000 volumio[957]: errno: -9, Apr 29 23:09:54 beolab-8000 volumio[957]: syscall: 'close', Apr 29 23:09:54 beolab-8000 volumio[957]: code: 'EBADF' Apr 29 23:09:54 beolab-8000 volumio[957]: } Apr 29 23:09:54 beolab-8000 volumio[957]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 29 23:09:54 beolab-8000 sudo[1825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-29 23:08 Apr 29 23:09:54 beolab-8000 sudo[1825]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"