-- Logs begin at Fri 2025-04-18 08:21:59 CEST, end at Fri 2025-04-18 10:00:23 CEST. -- Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:02 volumio volumio[9167]: error: error Apr 18 09:59:06 volumio volumio[9167]: info: UPDATER: Scheduling automatic update Apr 18 09:59:06 volumio volumio[9167]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStartTime Apr 18 09:59:06 volumio volumio[9167]: info: CoreCommandRouter::executeOnPlugin: system , getAutoUpdateWindowStopTime Apr 18 09:59:06 volumio volumio[9167]: info: UPDATER: Auto update will take place at: Sat Apr 19 2025 04:43:47 GMT+0200 (Central European Summer Time) Apr 18 09:59:06 volumio sudo[9191]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:34 volumio sudo[9831]: volumio : TTY=pts/3 ; PWD=/home/volumio/volumio-plugins-sources/motorized_fader_control ; USER=root ; COMMAND=/bin/systemctl stop volumio.service Apr 18 09:59:34 volumio sudo[9831]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:34 volumio systemd[1]: Stopping Volumio Backend Module... Apr 18 09:59:34 volumio volumio-remote-updater[564]: [2025-04-18 09:59:34] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Apr 18 09:59:34 volumio volumio-remote-updater[564]: [2025-04-18 09:59:34] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Apr 18 09:59:34 volumio systemd[1]: volumio.service: Main process exited, code=killed, status=15/TERM Apr 18 09:59:34 volumio systemd[1]: volumio.service: Succeeded. Apr 18 09:59:34 volumio go-librespot[9388]: time="2025-04-18T09:59:34+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Apr 18 09:59:34 volumio systemd[1]: Stopped Volumio Backend Module. Apr 18 09:59:34 volumio sudo[9831]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:34 volumio sudo[9834]: volumio : TTY=pts/3 ; PWD=/home/volumio/volumio-plugins-sources/motorized_fader_control ; USER=root ; COMMAND=/bin/systemctl start volumio.service Apr 18 09:59:34 volumio sudo[9834]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:34 volumio systemd[1]: Started Volumio Backend Module. Apr 18 09:59:34 volumio systemd[1]: Started dynamicswap service. Apr 18 09:59:34 volumio sudo[9834]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:34 volumio systemd[1]: dynamicswap.service: Succeeded. Apr 18 09:59:35 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:35 volumio volumio[9837]: info: ----- Volumio3 ---- Apr 18 09:59:35 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:35 volumio volumio[9837]: info: ----- System startup ---- Apr 18 09:59:35 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:35 volumio sudo[9871]: volumio : TTY=pts/3 ; PWD=/home/volumio/volumio-plugins-sources/motorized_fader_control ; USER=root ; COMMAND=/bin/journalctl -f Apr 18 09:59:35 volumio sudo[9871]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:35 volumio volumio[9837]: info: MYVOLUMIO Environment detected Apr 18 09:59:35 volumio volumio[9837]: info: Plugin folders cleanup Apr 18 09:59:35 volumio volumio[9837]: info: Scanning into folder /volumio/app/plugins/ Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category audio_interface Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category miscellanea Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category music_service Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category plugins.json Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category system_controller Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category user_interface Apr 18 09:59:35 volumio volumio[9837]: info: Scanning into folder /data/plugins/ Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category music_service Apr 18 09:59:35 volumio volumio[9837]: info: Scanning category system_hardware Apr 18 09:59:35 volumio volumio[9837]: info: Plugin folders cleanup completed Apr 18 09:59:35 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:35 volumio volumio[9837]: info: ----- Core plugins startup ---- Apr 18 09:59:35 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:35 volumio volumio[9837]: info: Loading plugins from folder /volumio/app/plugins/ Apr 18 09:59:35 volumio volumio[9837]: info: Adding plugin upnp to MyMusic Plugins Apr 18 09:59:35 volumio volumio[9837]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 18 09:59:35 volumio volumio[9837]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 18 09:59:35 volumio volumio[9837]: info: Loading plugins from folder /data/plugins/ Apr 18 09:59:35 volumio volumio[9837]: info: Loading plugin "system"... Apr 18 09:59:35 volumio volumio[9837]: info: Loading plugin "appearance"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "network"... Apr 18 09:59:36 volumio volumio[9837]: info: Refreshing Cached IP Addresses Apr 18 09:59:36 volumio sudo[9887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 18 09:59:36 volumio sudo[9887]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:36 volumio sudo[9887]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:36 volumio sudo[9889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 18 09:59:36 volumio sudo[9889]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:36 volumio sudo[9889]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "services"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "alsa_controller"... Apr 18 09:59:36 volumio sudo[9898]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 18 09:59:36 volumio sudo[9898]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:36 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "wizard"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "networkfs"... Apr 18 09:59:36 volumio volumio[9837]: info: Starting Udev Watcher for removable devices Apr 18 09:59:36 volumio volumio[9837]: info: Ignoring mount for partition: boot Apr 18 09:59:36 volumio volumio[9837]: info: Ignoring mount for partition: volumio Apr 18 09:59:36 volumio volumio[9837]: info: Ignoring mount for partition: volumio_data Apr 18 09:59:36 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "volumio_command_line_client"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "upnp"... Apr 18 09:59:36 volumio volumio[9837]: info: [1744963176442] Starting Upmpd Daemon Apr 18 09:59:36 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "my_music"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "mpd"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "upnp_browser"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "alarm-clock"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "airplay_emulation"... Apr 18 09:59:36 volumio volumio[9837]: info: Starting Shairport Sync Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "last_100"... Apr 18 09:59:36 volumio volumio[9837]: info: Loading plugin "webradio"... Apr 18 09:59:37 volumio volumio[9837]: info: Loading plugin "i2s_dacs"... Apr 18 09:59:37 volumio volumio[9837]: info: I2S DAC not set, start Auto-detection Apr 18 09:59:37 volumio volumio[9837]: info: Loading plugin "volumiodiscovery"... Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 09:59:37 volumio node[9837]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** For more information see Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 09:59:37 volumio volumio[9837]: *** WARNING *** For more information see Apr 18 09:59:37 volumio node[9837]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 09:59:37 volumio node[9837]: *** WARNING *** For more information see Apr 18 09:59:37 volumio node[9837]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 18 09:59:37 volumio node[9837]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 18 09:59:37 volumio node[9837]: *** WARNING *** For more information see Apr 18 09:59:37 volumio volumio[9837]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 18 09:59:37 volumio volumio[9837]: info: Discovery: Started advertising with name: Volumio Apr 18 09:59:37 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 09:59:37 volumio volumio[9837]: info: Loading plugin "jellyfin"... Apr 18 09:59:37 volumio volumio[9837]: info: Loading plugin "spop"... Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "outputs"... Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "albumart"... Apr 18 09:59:38 volumio volumio[9837]: info: Plugin example_plugin is not enabled Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "inputs"... Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "updater_comm"... Apr 18 09:59:38 volumio volumio[9837]: info: Plugin mpdemulation is not enabled Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "rest_api"... Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "websocket"... Apr 18 09:59:38 volumio volumio[9837]: info: Starting Socket.io Server version 2.3.0 Apr 18 09:59:38 volumio volumio[9837]: info: Loading plugin "motorized_fader_control"... Apr 18 09:59:38 volumio volumio[9837]: Forking 3 albumart workers Apr 18 09:59:39 volumio volumio[9837]: info: Loading i18n strings for locale de Apr 18 09:59:39 volumio volumio[9837]: Updating browse sources language Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:39 volumio volumio-remote-updater[564]: [2025-04-18 09:59:39] [connect] Successful connection Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::initPlayerControls Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: Express server listening on port 3000 Apr 18 09:59:39 volumio volumio[9837]: [Metrics] WebUI: 4s 298.33ms Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::resetVolumioState Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::getcurrentVolume Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioRetrievevolume Apr 18 09:59:39 volumio volumio[9837]: Starting albumart workers Apr 18 09:59:39 volumio volumio[9837]: Starting albumart workers Apr 18 09:59:39 volumio volumio[9837]: Starting albumart workers Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: Volumio Network Manager: Network status updated: 2 Apr 18 09:59:39 volumio volumio[9837]: verbose: New Socket.io Connection to 192.168.2.116 from 192.168.2.105 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 18 09:59:39 volumio volumio-remote-updater[564]: [2025-04-18 09:59:39] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1744963179 101 Apr 18 09:59:39 volumio volumio[9837]: 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: 2 Apr 18 09:59:39 volumio volumio[9837]: info: Reloading queue from file Apr 18 09:59:39 volumio volumio[9837]: info: VolumeController:: Volume=80 Mute =false Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::updateTrackBlock Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrackBlock Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioRetrievevolume Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::setRepeat true single undefined Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::setRandom true Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 09:59:39 volumio volumio[9837]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Apr 18 09:59:39 volumio volumio[9837]: info: USB Boot Capable - System SBC Revision found in cpuinfo: b03115 Apr 18 09:59:39 volumio volumio[9837]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Apr 18 09:59:39 volumio volumio[9837]: info: Setting Device type: Raspberry PI Apr 18 09:59:39 volumio volumio[9837]: verbose: New Socket.io Connection to 192.168.2.116 from 192.168.2.105 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: 3 Apr 18 09:59:39 volumio volumio[9837]: info: Completed loading Core Plugins Apr 18 09:59:39 volumio volumio[9837]: info: Preparing to generate the ALSA configuration file Apr 18 09:59:39 volumio volumio[9837]: info: VolumeController:: Volume=80 Mute =false Apr 18 09:59:39 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 09:59:39 volumio volumio[9837]: info: Asound.conf file unchanged, so no further update is needed Apr 18 09:59:39 volumio volumio[9837]: info: Output device has changed, restarting MPD Apr 18 09:59:39 volumio sudo[9981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 18 09:59:39 volumio sudo[9981]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:39 volumio volumio[9837]: info: Output device has changed, restarting Shairport Sync Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:39 volumio sudo[9981]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:39 volumio sudo[9984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 18 09:59:39 volumio sudo[9984]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:39 volumio systemd[1]: Stopping Music Player Daemon... Apr 18 09:59:39 volumio volumio[9837]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 09:59:39 volumio volumio[9837]: info: ___________ START PLUGINS ___________ Apr 18 09:59:39 volumio volumio[9837]: info: ControllerMpd::onStart: Initializing MPD Apr 18 09:59:39 volumio volumio[9837]: info: Creating MPD Configuration file Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 09:59:39 volumio volumio[9837]: info: [1744963179820] CoreMusicLibrary::Adding element Medienserver Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:39 volumio sudo[9990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 18 09:59:39 volumio sudo[9992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 18 09:59:39 volumio sudo[9992]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:39 volumio sudo[9990]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:39 volumio sudo[9990]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 09:59:39 volumio volumio[9837]: info: [1744963179921] CoreMusicLibrary::Adding element Last_100 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 09:59:39 volumio volumio[9837]: info: [1744963179924] CoreMusicLibrary::Adding element Webradio Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 09:59:39 volumio volumio[9837]: info: Initializing BBC Radios Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 18 09:59:39 volumio volumio[9837]: info: Discovery: Getting this device information Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:39 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:39 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 18 09:59:39 volumio systemd[1]: mpd.service: Succeeded. Apr 18 09:59:39 volumio systemd[1]: Stopped Music Player Daemon. Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 09:59:40 volumio volumio[9837]: info: [1744963180007] CoreMusicLibrary::Adding element Jellyfin Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:40 volumio volumio[9837]: Cannot find translation for source Jellyfin Apr 18 09:59:40 volumio volumio[9837]: info: [jellyfin] Initialized plugin with device info: {"id":"57a5d2e1-7fee-45e4-a1ed-a7da52e1e961","host":"http://192.168.2.116","name":"Volumio","type":"device","serviceName":"Volumio","state":{"status":"stop","volume":80,"mute":false,"artist":"Isaac Hayes","track":"Monologue: Ike's Rap I","albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg"}} Apr 18 09:59:40 volumio sudo[9898]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:40 volumio volumio[9837]: info: Creating Spotify config file Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio systemd[1]: Starting Music Player Daemon... Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Log level changed to: debug Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Log messages initialized successfully. Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: -------------------------------------------------------------------- Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Starting motorized fader control plugin... Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: -------------------------------------------------------------------- Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Initializing core components... Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Setting up plugin... Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Initializing FaderController... Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: emitting configChange for fader 0 Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: emitting configChange for fader 1 Apr 18 09:59:40 volumio volumio[9837]: info: Volumio Calling Home Apr 18 09:59:40 volumio sudo[10011]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 18 09:59:40 volumio sudo[10011]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:40 volumio sudo[10011]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: MIDILog: true Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: ValueLog: true Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: MoveLog: true Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: messageDelay: 0.1 Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: speeds: 100,50,10 Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: faderIndexes: 0,1 Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: queueOverflow: 10000000 Apr 18 09:59:40 volumio volumio[9837]: debug: [FaderController]: calibrateOnStart: true Apr 18 09:59:40 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: fader/update Apr 18 09:59:40 volumio volumio[9837]: info: [motorized_fader_control]: Starting FaderController... Apr 18 09:59:40 volumio volumio[9837]: info: Discovery: adding 57a5d2e1-7fee-45e4-a1ed-a7da52e1e961 Apr 18 09:59:40 volumio volumio[9837]: info: Discovery: Found device Volumio Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:40 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:40 volumio volumio[9837]: debug: API:pushMultiroomDevices Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 18 09:59:40 volumio volumio[9837]: info: MPD Permissions set Apr 18 09:59:40 volumio volumio[9837]: info: MPD Permissions set Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetVisibleSources Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:40 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:40 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 18 09:59:40 volumio volumio[9837]: info: Received Get System Info Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 18 09:59:40 volumio volumio[9837]: info: Discovery: Getting this device information Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:40 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:40 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:40 volumio volumio[9837]: info: Listing playlists Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::volumioGetQueue Apr 18 09:59:40 volumio volumio[9837]: info: CoreStateMachine::getQueue Apr 18 09:59:40 volumio volumio[9837]: info: CorePlayQueue::getQueue Apr 18 09:59:40 volumio volumio[9837]: info: [jellyfin-poller] Polled http://192.168.2.158:8096: online Apr 18 09:59:40 volumio volumio[9837]: info: Spotify config file written Apr 18 09:59:40 volumio sudo[10031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 18 09:59:40 volumio sudo[10031]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:40 volumio systemd[1]: Stopping go-librespot Daemon... Apr 18 09:59:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 18 09:59:40 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Apr 18 09:59:40 volumio systemd[1]: Stopped go-librespot Daemon. Apr 18 09:59:40 volumio volumio[9837]: 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 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio systemd[1]: Started go-librespot Daemon. Apr 18 09:59:40 volumio go-librespot[10033]: Librespot-go daemon starting... Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio sudo[10031]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=info msg="generated new device id: 8b93faf30f02a98e6603fbfddc32dd71e0c790d3" Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=debug msg="stored credentials found for lemur30" Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 09:59:40 volumio volumio[9837]: info: No need to fix Spotify hosts Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+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 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+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 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+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 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=debug msg="zeroconf server listening on port 37857" Apr 18 09:59:40 volumio volumio[9837]: info: Volumio called home Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=debug msg="obtained new client token: AAD0DCHJvf5ldpHQ/OOF/kEfb84fODCcxAo7+ZlsLzSk1Ie6+wZX9mKCa3RLUcdiz2kTjIgKwhYPxOqkYZLadNetoPV0Qc27zkFhgCvP3LC2atUogwXJX/U2KC0yZw1fKS214AZCI+QP7ivN9BN1RuLRUccx0mI6A2bw5EoUhnREWWO67yp0TmjHrH4YFOpZ0wzPa1NIWwgOwFGZOCVn5qH1oTiZzFF6NI3X7N7u80YjLDZYpN8asM+G3MrV5Q==" Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Apr 18 09:59:40 volumio go-librespot[10033]: time="2025-04-18T09:59:40+02:00" level=debug msg="completed keyexchange" Apr 18 09:59:40 volumio volumio[9837]: info: Starting Shairport Sync Apr 18 09:59:40 volumio volumio[9837]: info: Starting Shairport Sync Apr 18 09:59:40 volumio sudo[10052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 09:59:40 volumio sudo[10052]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:40 volumio volumio[9837]: info: Starting Shairport Sync Apr 18 09:59:40 volumio sudo[10054]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 09:59:40 volumio sudo[10054]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:40 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 09:59:41 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 18 09:59:41 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 09:59:41 volumio sudo[10058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 18 09:59:41 volumio volumio[9837]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 09:59:41 volumio volumio[9837]: SPOTIFY: BQD7wRGtImihr0DYnYpvDMd3Xf0tGxNpJ0GYCzkSQRGC3tXXtTla_XXaaR-UwL1v3dTBd2A4DJDBjQ3Fme3gvmKnkmc-D4_G3Nb9C7LAztCf3Oi8j1BF53iy4fE8KIYPJ9ssQg2ArC-13It3UTNv41f9h-wervztHHIs6iuGPwPgDYobTCOux2pK6c2sdS4gVqPuI4GW5yYJdwhnii7YAA6xIPj8AQbV9z_raftCc6gfr4qjFe7mBQqcq7XoXX-opv9meFfN_S4BbH0iAXA Apr 18 09:59:41 volumio volumio[9837]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 18 09:59:41 volumio sudo[10058]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:41 volumio volumio[9837]: info: New Spotify access token = BQD7wRGtImihr0DYnYpvDMd3Xf0tGxNpJ0GYCzkSQRGC3tXXtTla_XXaaR-UwL1v3dTBd2A4DJDBjQ3Fme3gvmKnkmc-D4_G3Nb9C7LAztCf3Oi8j1BF53iy4fE8KIYPJ9ssQg2ArC-13It3UTNv41f9h-wervztHHIs6iuGPwPgDYobTCOux2pK6c2sdS4gVqPuI4GW5yYJdwhnii7YAA6xIPj8AQbV9z_raftCc6gfr4qjFe7mBQqcq7XoXX-opv9meFfN_S4BbH0iAXA Apr 18 09:59:41 volumio volumio[9837]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 18 09:59:41 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:41 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:41 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:41 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 09:59:41 volumio sudo[10052]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:41 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 18 09:59:41 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 18 09:59:41 volumio systemd[1]: shairport-sync.service: Succeeded. Apr 18 09:59:41 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 18 09:59:41 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 18 09:59:41 volumio volumio[9837]: info: Shairport-Sync Started Apr 18 09:59:41 volumio volumio[9837]: Error adding Membership: Error: addMembership EINVAL Apr 18 09:59:41 volumio sudo[10054]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:41 volumio sudo[10058]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:41 volumio volumio[9837]: info: Shairport-Sync Started Apr 18 09:59:41 volumio volumio[9837]: info: Shairport-Sync Started Apr 18 09:59:41 volumio volumio[9837]: SPOTIFY: User informations: {"country":"DE","display_name":"lemur30","email":"lemur30@gmx.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/lemur30"},"followers":{"href":null,"total":12},"href":"https://api.spotify.com/v1/users/lemur30","id":"lemur30","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee85fed857b2b5289d2be781bc6c","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b82fed857b2b5289d2be781bc6c","width":64}],"product":"premium","type":"user","uri":"spotify:user:lemur30"} Apr 18 09:59:41 volumio volumio[9837]: info: Spotify Successfully logged in Apr 18 09:59:41 volumio volumio[9837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 18 09:59:41 volumio volumio[9837]: info: [1744963181211] CoreMusicLibrary::Adding element Spotify Apr 18 09:59:41 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 18 09:59:41 volumio volumio[9837]: Cannot find translation for source Jellyfin Apr 18 09:59:41 volumio volumio[9837]: Cannot find translation for source Spotify Apr 18 09:59:41 volumio volumio[9837]: debug: API:emitFavourites Apr 18 09:59:41 volumio mpd[10028]: Apr 18 09:59 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 18 09:59:41 volumio systemd[1]: Started Music Player Daemon. Apr 18 09:59:41 volumio sudo[9992]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:41 volumio sudo[9984]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:41 volumio volumio[9837]: debug: API:printToastMessage Apr 18 09:59:41 volumio volumio[9837]: error: MPD error: The expression evaluated to a falsy value: Apr 18 09:59:41 volumio volumio[9837]: assert.ok(self.idling) Apr 18 09:59:41 volumio volumio[9837]: error: The expression evaluated to a falsy value: Apr 18 09:59:41 volumio volumio[9837]: assert.ok(self.idling) Apr 18 09:59:41 volumio volumio[9837]: info: MPD running with PID10028 Apr 18 09:59:41 volumio volumio[9837]: ,establishing connection Apr 18 09:59:41 volumio volumio[9837]: error: updateQueue error: null Apr 18 09:59:41 volumio volumio[9837]: error: updateQueue error: null Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="completed challenge" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="authenticated as lemur30" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="authenticated as lemur30" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,102]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,40]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,51]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,115]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="dealer connection opened" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="initializing zeroconf session, username: lemur30" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,116]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,40]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,57]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="autoplay enabled: false" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,50]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController] [MIDIHandler]: MIDI RECV: {"raw":{"type":"Buffer","data":[192,2,160,52]},"type":"PROGRAM_CHANGE","channel":1,"data1":2} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI HANDLE: PROGRAM_CHANGE Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="received connection id: ZTE3Mzk0MjItNjBiOS00NjkxLWI2ZjktYjk2MDQ5NDAyNGQwK2RlYWxlcit0Y3A6Ly8wYWNhNWEzMC5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMDY3NzFGRTIxNDE0QTYzNDY2RDRBOThEMDY0NUNBNTI4MEMxM0ZERjUwM0E3QkFDNkYwNkJBNTM0RTI4NUUyRQ==" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Device check attempt 1/10 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI device ready signal received Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Calibrating... Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[0,0],"speeds":[100,100],"resolution":1} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Generated 2 positions Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Positions: [{"index":0,"value":0},{"index":1,"value":0}] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: First position: 0, Last position: 0 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[100,100],"speeds":[100,100],"resolution":1} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 100.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Generated 4 positions Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Positions: [{"index":0,"value":0},{"index":0,"value":16383},{"index":1,"value":0},{"index":1,"value":16383}] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: First position: 0, Last position: 16383 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,127,127] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,127,127] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Move: {"indexes":[0,1],"targets":[0,0],"speeds":[99,99],"resolution":1} Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 0 speedFactor: 1.00, effectiveSpeed: 99.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Fader 1 speedFactor: 1.00, effectiveSpeed: 99.00 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Generated 164 positions Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: Positions: [{"index":0,"value":16383},{"index":0,"value":16181},{"index":0,"value":15978},{"index":0,"value":15776},{"index":0,"value":15574},{"index":0,"value":15372},{"index":0,"value":15169},{"index":0,"value":14967},{"index":0,"value":14765},{"index":0,"value":14563},{"index":0,"value":14360},{"index":0,"value":14158},{"index":0,"value":13956},{"index":0,"value":13754},{"index":0,"value":13551},{"index":0,"value":13349},{"index":0,"value":13147},{"index":0,"value":12945},{"index":0,"value":12742},{"index":0,"value":12540},{"index":0,"value":12338},{"index":0,"value":12136},{"index":0,"value":11933},{"index":0,"value":11731},{"index":0,"value":11529},{"index":0,"value":11327},{"index":0,"value":11124},{"index":0,"value":10922},{"index":0,"value":10720},{"index":0,"value":10517},{"index":0,"value":10315},{"index":0,"value":10113},{"index":0,"value":9911},{"index":0,"value":9708},{"index":0,"value":9506},{"index":0,"value":9304},{"index":0,"value":9102},{"index":0,"value":8899},{"index":0,"value":8697},{"index":0,"value":8495},{"index":0,"value":8293},{"index":0,"value":8090},{"index":0,"value":7888},{"index":0,"value":7686},{"index":0,"value":7484},{"index":0,"value":7281},{"index":0,"value":7079},{"index":0,"value":6877},{"index":0,"value":6675},{"index":0,"value":6472},{"index":0,"value":6270},{"index":0,"value":6068},{"index":0,"value":5866},{"index":0,"value":5663},{"index":0,"value":5461},{"index":0,"value":5259},{"index":0,"value":5056},{"index":0,"value":4854},{"index":0,"value":4652},{"index":0,"value":4450},{"index":0,"value":4247},{"index":0,"value":4045},{"index":0,"value":3843},{"index":0,"value":3641},{"index":0,"value":3438},{"index":0,"value":3236},{"index":0,"value":3034},{"index":0,"value":2832},{"index":0,"value":2629},{"index":0,"value":2427},{"index":0,"value":2225},{"index":0,"value":2023},{"index":0,"value":1820},{"index":0,"value":1618},{"index":0,"value":1416},{"index":0,"value":1214},{"index":0,"value":1011},{"index":0,"value":809},{"index":0,"value":607},{"index":0,"value":405},{"index":0,"value":202},{"index":0,"value":0},{"index":1,"value":16383},{"index":1,"value":16181},{"index":1,"value":15978},{"index":1,"value":15776},{"index":1,"value":15574},{"index":1,"value":15372},{"index":1,"value":15169},{"index":1,"value":14967},{"index":1,"value":14765},{"index":1,"value":14563},{"index":1,"value":14360},{"index":1,"value":14158},{"index":1,"value":13956},{"index":1,"value":13754},{"index":1,"value":13551},{"index":1,"value":13349},{"index":1,"value":13147},{"index":1,"value":12945},{"index":1,"value":12742},{"index":1,"value":12540},{"index":1,"value":12338},{"index":1,"value":12136},{"index":1,"value":11933},{"index":1,"value":11731},{"index":1,"value":11529},{"index":1,"value":11327},{"index":1,"value":11124},{"index":1,"value":10922},{"index":1,"value":10720},{"index":1,"value":10517},{"index":1,"value":10315},{"index":1,"value":10113},{"index":1,"value":9911},{"index":1,"value":9708},{"index":1,"value":9506},{"index":1,"value":9304},{"index":1,"value":9102},{"index":1,"value":8899},{"index":1,"value":8697},{"index":1,"value":8495},{"index":1,"value":8293},{"index":1,"value":8090},{"index":1,"value":7888},{"index":1,"value":7686},{"index":1,"value":7484},{"index":1,"value":7281},{"index":1,"value":7079},{"index":1,"value":6877},{"index":1,"value":6675},{"index":1,"value":6472},{"index":1,"value":6270},{"index":1,"value":6068},{"index":1,"value":5866},{"index":1,"value":5663},{"index":1,"value":5461},{"index":1,"value":5259},{"index":1,"value":5056},{"index":1,"value":4854},{"index":1,"value":4652},{"index":1,"value":4450},{"index":1,"value":4247},{"index":1,"value":4045},{"index":1,"value":3843},{"index":1,"value":3641},{"index":1,"value":3438},{"index":1,"value":3236},{"index":1,"value":3034},{"index":1,"value":2832},{"index":1,"value":2629},{"index":1,"value":2427},{"index":1,"value":2225},{"index":1,"value":2023},{"index":1,"value":1820},{"index":1,"value":1618},{"index":1,"value":1416},{"index":1,"value":1214},{"index":1,"value":1011},{"index":1,"value":809},{"index":1,"value":607},{"index":1,"value":405},{"index":1,"value":202},{"index":1,"value":0}] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: First position: 16383, Last position: 0 Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,127,127] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,127,127] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,53,126] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,53,126] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,106,124] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,106,124] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,32,123] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,32,123] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,86,121] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,86,121] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,12,120] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,12,120] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,65,118] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,65,118] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,119,116] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,119,116] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,45,115] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,45,115] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,99,113] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,99,113] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,24,112] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,24,112] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,78,110] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,78,110] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,4,109] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,4,109] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,58,107] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,58,107] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,111,105] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,111,105] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,37,104] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,37,104] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,91,102] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,91,102] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,17,101] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,17,101] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,70,99] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,70,99] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,124,97] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,124,97] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,50,96] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,50,96] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,104,94] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,104,94] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,29,93] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,29,93] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,83,91] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,83,91] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,9,90] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,9,90] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,63,88] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,63,88] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,116,86] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,116,86] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,42,85] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,42,85] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,96,83] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,96,83] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,21,82] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,21,82] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,75,80] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,75,80] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,1,79] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,1,79] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,55,77] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,55,77] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,108,75] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,108,75] Apr 18 09:59:41 volumio go-librespot[10033]: time="2025-04-18T09:59:41+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,34,74] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,34,74] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,88,72] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,88,72] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,14,71] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,14,71] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,67,69] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,67,69] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,121,67] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,121,67] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,47,66] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,47,66] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,101,64] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,101,64] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,26,63] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,26,63] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,80,61] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,80,61] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,6,60] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,6,60] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,60,58] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,60,58] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,113,56] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,113,56] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,39,55] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,39,55] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,93,53] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,93,53] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,19,52] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,19,52] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,72,50] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,72,50] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,126,48] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,126,48] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,52,47] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,52,47] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,106,45] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,106,45] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,31,44] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,31,44] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,85,42] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,85,42] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,11,41] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,11,41] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,64,39] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,64,39] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,118,37] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,118,37] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,44,36] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,44,36] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,98,34] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,98,34] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,23,33] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,23,33] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,77,31] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,77,31] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,3,30] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,3,30] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,57,28] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,57,28] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,110,26] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,110,26] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,36,25] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,36,25] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,90,23] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,90,23] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,16,22] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,16,22] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,69,20] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,69,20] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,123,18] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,123,18] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,49,17] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,49,17] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,103,15] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,103,15] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,28,14] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,28,14] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,82,12] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,82,12] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,8,11] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,8,11] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,62,9] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,62,9] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,115,7] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,115,7] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,41,6] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,41,6] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,95,4] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,95,4] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,21,3] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,21,3] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,74,1] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,74,1] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [224,0,0] Apr 18 09:59:41 volumio volumio[9837]: debug: [FaderController]: MIDI SEND: [225,0,0] Apr 18 09:59:41 volumio volumio[9837]: info: FaderController started successfully Apr 18 09:59:41 volumio volumio[9837]: info: [motorized_fader_control]: FaderController started successfully Apr 18 09:59:41 volumio volumio[9837]: info: [motorized_fader_control]: Starting service connections... Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Connected to Volumio at localhost:3000 Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: command/volumio/getAlbumInfo Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: command/volumio/getQueueInfo Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/playing Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/paused Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/stopped Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: fader/0/move Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: fader/0/move/end Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: validated/state Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/playing Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/paused Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: playback/stopped Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: fader/1/move Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: fader/1/move/end Apr 18 09:59:41 volumio volumio[9837]: debug: [motorized_fader_control]: Event registered: validated/state Apr 18 09:59:41 volumio volumio[9837]: info: [motorized_fader_control]: Plugin started successfully! Apr 18 09:59:41 volumio volumio[9837]: info: [motorized_fader_control]: -------------------------------------------------------------------- Apr 18 09:59:41 volumio volumio[9837]: info: Completed starting Core Plugins Apr 18 09:59:41 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:41 volumio volumio[9837]: info: ----- MyVolumio plugins startup ---- Apr 18 09:59:41 volumio volumio[9837]: info: ------------------------------------------- Apr 18 09:59:41 volumio volumio[9837]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 18 09:59:41 volumio volumio[9837]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Apr 18 09:59:41 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:41 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:41 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:42 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963182001 Apr 18 09:59:42 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/stopped {"status":"stop","position":0,"title":"Monologue: Ike's Rap I","artist":"Isaac Hayes","album":"...To Be Continued","albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","seek":0,"duration":238,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":80,"dbVolume":null,"disableVolumeControl":false,"mute":false,"updatedb":false,"volatile":false,"service":"upnp_browser"} Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: error: error Apr 18 09:59:43 volumio volumio[9837]: info: go-librespot daemon successfully initialized Apr 18 09:59:46 volumio volumio[9837]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Apr 18 09:59:46 volumio sudo[10132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 18 09:59:46 volumio sudo[10132]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:46 volumio sudo[10132]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:46 volumio sudo[10135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 18 09:59:46 volumio sudo[10135]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:46 volumio sudo[10135]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:46 volumio sudo[10139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 18 09:59:46 volumio sudo[10139]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:46 volumio sudo[10139]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:46 volumio volumio[9837]: info: Upmpdcli Daemon Started Apr 18 09:59:46 volumio volumio[9837]: info: Initializing connection to go-librespot Websocket Apr 18 09:59:46 volumio go-librespot[10033]: time="2025-04-18T09:59:46+02:00" level=debug msg="new websocket client" Apr 18 09:59:46 volumio volumio[9837]: info: Connection to go-librespot Websocket established Apr 18 09:59:49 volumio volumio[9837]: info: Getting Spotify volume Apr 18 09:59:49 volumio volumio[9837]: info: Spotify volume: 100 Apr 18 09:59:49 volumio volumio[9837]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 18 09:59:49 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 09:59:49 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 09:59:49 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 09:59:49 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 09:59:49 volumio volumio[9837]: SPOTIFY: SPOTIFY VOLUME 100 Apr 18 09:59:49 volumio volumio[9837]: SPOTIFY: VOLUMIO VOLUME 80 Apr 18 09:59:49 volumio volumio[9837]: SPOTIFY: DELTA VOLUME ENOUGH: true Apr 18 09:59:49 volumio volumio[9837]: info: Setting Spotify Volume from Volumio: 80 Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin bluetooth to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin multiroom to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin metavolumio to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin cd_controller to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin smart_inputs to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: Adding plugin tidalconnect to MyMusic Plugins Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Apr 18 09:59:50 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:50 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:50 volumio volumio[9837]: info: Starting MyVolumio Remote Streaming Endpoints Apr 18 09:59:50 volumio volumio[9837]: info: MyVolumio login type: Token Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Apr 18 09:59:50 volumio volumio[9837]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Apr 18 09:59:51 volumio volumio[9837]: info: Starting Streaming Service Transparent Proxy Apr 18 09:59:51 volumio volumio[9837]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Apr 18 09:59:51 volumio volumio[9837]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Apr 18 09:59:51 volumio volumio[9837]: info: Streaming services startup Apr 18 09:59:51 volumio volumio[9837]: info: Starting Streaming Daemon Apr 18 09:59:51 volumio sudo[10191]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 18 09:59:51 volumio sudo[10191]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:51 volumio sudo[10191]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:51 volumio volumio[9837]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Apr 18 09:59:51 volumio volumio[9837]: SPOTIFY: SETTING SPOTIFY VOLUME 80 Apr 18 09:59:51 volumio volumio[9837]: info: Sending Spotify command with payload to local API: /player/volume Apr 18 09:59:51 volumio go-librespot[10033]: time="2025-04-18T09:59:51+02:00" level=debug msg="update volume to 52428/65535" Apr 18 09:59:51 volumio volumio[9837]: error: Cannot start Volumio Streaming Daemon Apr 18 09:59:51 volumio volumio[9837]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 18 09:59:51 volumio volumio[9837]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 18 09:59:51 volumio go-librespot[10033]: time="2025-04-18T09:59:51+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Apr 18 09:59:51 volumio go-librespot[10033]: time="2025-04-18T09:59:51+02:00" level=trace msg="emitting websocket event: volume" Apr 18 09:59:51 volumio volumio[9837]: SPOTIFY: received: {"type":"volume","data":{"value":80,"max":100}} Apr 18 09:59:51 volumio volumio[9837]: SPOTIFY: RECEIVED SPOTIFY VOLUME 80 Apr 18 09:59:52 volumio volumio[9837]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 18 09:59:52 volumio volumio[9837]: STREAMING PROXY: Starting server on port 3245 Apr 18 09:59:52 volumio volumio[9837]: Node JS runtime: 14 Apr 18 09:59:52 volumio volumio[9837]: info: MyVolumio token set successfully Apr 18 09:59:52 volumio volumio[9837]: info: MYVOLUMIO: Adding device Apr 18 09:59:52 volumio volumio[9837]: info: MYVOLUMIO: Evaluating Server Apr 18 09:59:53 volumio volumio[9837]: info: MyVolumio status changed Apr 18 09:59:53 volumio volumio[9837]: info: Streaming services startup Apr 18 09:59:53 volumio volumio[9837]: info: Starting Streaming Daemon Apr 18 09:59:53 volumio volumio[9837]: info: Removing browser output: myVolumio user plan is not superstar Apr 18 09:59:53 volumio volumio[9837]: info: Removing audio output: Apr 18 09:59:53 volumio volumio[9837]: info: Stoppping Tunnel 1 Apr 18 09:59:53 volumio sudo[10218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 18 09:59:53 volumio sudo[10218]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:53 volumio sudo[10218]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:53 volumio sudo[10221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Apr 18 09:59:53 volumio sudo[10221]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 18 09:59:53 volumio volumio[9837]: error: Cannot start Volumio Streaming Daemon Apr 18 09:59:53 volumio volumio[9837]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 18 09:59:53 volumio volumio[9837]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 18 09:59:53 volumio sudo[10221]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:53 volumio volumio[9837]: info: Remote SSH Stopped Apr 18 09:59:53 volumio sudo[9871]: pam_unix(sudo:session): session closed for user root Apr 18 09:59:53 volumio volumio[9837]: info: Setting Geolocation for MyVolumio to eu6 Apr 18 09:59:53 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:53 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:53 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:53 volumio volumio[9837]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 18 09:59:54 volumio volumio[9837]: info: Updating MyVolumio device info Apr 18 09:59:54 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:54 volumio volumio[9837]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 18 09:59:57 volumio volumio[9837]: info: MYVOLUMIO: Adding device Apr 18 09:59:57 volumio volumio[9837]: info: MYVOLUMIO: Evaluating Server Apr 18 09:59:58 volumio volumio[9837]: info: Setting Geolocation for MyVolumio to eu10 Apr 18 09:59:58 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:58 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:58 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:59 volumio volumio[9837]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Apr 18 09:59:59 volumio volumio[9837]: info: Updating MyVolumio device info Apr 18 09:59:59 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:59 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 09:59:59 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 10:00:00 volumio volumio[9837]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Apr 18 10:00:05 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 18 10:00:05 volumio volumio[9837]: debug: API:emitFavourites Apr 18 10:00:05 volumio volumio[9837]: 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 18 10:00:05 volumio volumio[9837]: info: CoreCommandRouter::volumioGetState Apr 18 10:00:05 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:05 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:07 volumio sshd[5605]: Received disconnect from 192.168.2.105 port 50541:11: disconnected by user Apr 18 10:00:07 volumio sshd[5605]: Disconnected from user volumio 192.168.2.105 port 50541 Apr 18 10:00:07 volumio sshd[5535]: pam_unix(sshd:session): session closed for user volumio Apr 18 10:00:07 volumio systemd-logind[569]: Session 1 logged out. Waiting for processes to exit. Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 18 10:00:10 volumio volumio[9837]: debug: API:emitFavourites Apr 18 10:00:10 volumio volumio-remote-updater[564]: No test mode Apr 18 10:00:10 volumio volumio-remote-updater[564]: No alpha test mode Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Apr 18 10:00:10 volumio volumio[9837]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

    • Improved translations


NEW ADDITIONS

 

    • Update to TIDAL Connect
    • Add Install-to-disk option for the new RPi5 HW revisions 

 

","title":"Update v3.799","updateavailable":true} Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::volumioGetBrowseSources Apr 18 10:00:10 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 18 10:00:11 volumio volumio[9837]: error: MyVolumio Plugin failed to authenticate in a timely fashion Apr 18 10:00:11 volumio volumio[9837]: info: Completed starting MyVolumio Plugin Apr 18 10:00:11 volumio volumio[9837]: [Metrics] CommandRouter: 36s 378.06ms Apr 18 10:00:11 volumio volumio[9837]: info: CoreCommandRouter::volumiosetStartupVolume Apr 18 10:00:11 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 18 10:00:11 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 18 10:00:11 volumio volumio[9837]: info: CoreCommandRouter::Close All Modals sent Apr 18 10:00:11 volumio volumio[9837]: debug: API:emitFavourites Apr 18 10:00:11 volumio volumio[9837]: info: CoreCommandRouter::Close All Modals sent Apr 18 10:00:11 volumio volumio[9837]: debug: API:emitFavourites Apr 18 10:00:12 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Apr 18 10:00:12 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 18 10:00:12 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Apr 18 10:00:16 volumio volumio[9837]: info: CoreCommandRouter::volumioPlay Apr 18 10:00:16 volumio volumio[9837]: info: CoreStateMachine::play index undefined Apr 18 10:00:16 volumio volumio[9837]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 18 10:00:16 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:16 volumio volumio[9837]: info: CoreStateMachine::startPlaybackTimer Apr 18 10:00:16 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:16 volumio volumio[9837]: info: [1744963216934] ControllerUPNPBrowser::clearAddPlayTrack Apr 18 10:00:16 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand stop Apr 18 10:00:16 volumio volumio[9837]: info: sendMpdCommand stop took 1 milliseconds Apr 18 10:00:16 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand clear Apr 18 10:00:16 volumio volumio[9837]: info: Apr 18 10:00:16 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:16 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:16 volumio volumio[9837]: info: sendMpdCommand clear took 2 milliseconds Apr 18 10:00:16 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 10:00:16 volumio volumio[9837]: info: Apr 18 10:00:16 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:16 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:16 volumio volumio[9837]: info: Apr 18 10:00:16 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:16 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:16 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:16 volumio volumio[9837]: info: ------------------------------ 6ms Apr 18 10:00:18 volumio volumio[9837]: info: BOOT COMPLETED Apr 18 10:00:21 volumio volumio[9837]: info: CoreCommandRouter::volumioPlay Apr 18 10:00:21 volumio volumio[9837]: info: CoreStateMachine::play index undefined Apr 18 10:00:21 volumio volumio[9837]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 18 10:00:21 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:21 volumio volumio[9837]: info: CoreStateMachine::startPlaybackTimer Apr 18 10:00:21 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:21 volumio volumio[9837]: info: [1744963221176] ControllerUPNPBrowser::clearAddPlayTrack Apr 18 10:00:21 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand stop Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 5321ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 5321ms Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand stop took 1083 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" took 3 milliseconds Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand clear Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand play Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 7ms Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand clear took 6 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand play took 5 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 5ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 4ms Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 6ms Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: error: updateQueue error: null Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 178ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 178ms Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand add "http://192.168.2.158:8200/MediaItems/74334.flac" took 2 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::setConsumeUpdateService mpd Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand play Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces system playlist update Apr 18 10:00:22 volumio volumio[9837]: info: Ignoring MPD Status Update Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 7ms Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand play took 5 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 6ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 4ms Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 4 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 3 milliseconds Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 6 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 6 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 5 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 3 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 3 milliseconds Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus stop Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus play Apr 18 10:00:22 volumio volumio[9837]: info: Received an update from plugin. extracting info from payload Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 34ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 44ms Apr 18 10:00:22 volumio volumio[9837]: info: Apr 18 10:00:22 volumio volumio[9837]: ---------------------------- MPD announces state update: player Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::getState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand status Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 33 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 31 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 31 milliseconds Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand status took 2 milliseconds Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseState Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::sendMpdCommand playlistinfo Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus play Apr 18 10:00:22 volumio volumio[9837]: info: Received an update from plugin. extracting info from payload Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus play Apr 18 10:00:22 volumio volumio[9837]: info: Received an update from plugin. extracting info from payload Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus play Apr 18 10:00:22 volumio volumio[9837]: info: Received an update from plugin. extracting info from payload Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 92ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 87ms Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 86ms Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222583 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":"","album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.0008368200836820083 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.002092050209205021 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.002092050209205021],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222589 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0016736401673640166 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0016736401673640166],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222595 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222598 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222602 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222606 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0012552301255230125 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0012552301255230125],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222611 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0016736401673640166 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0016736401673640166],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222617 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: info: sendMpdCommand playlistinfo took 100 milliseconds Apr 18 10:00:22 volumio volumio[9837]: verbose: ControllerMpd::parseTrackInfo Apr 18 10:00:22 volumio volumio[9837]: info: ControllerMpd::pushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::servicePushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::syncState Apr 18 10:00:22 volumio volumio[9837]: info: CorePlayQueue::getTrack 0 Apr 18 10:00:22 volumio volumio[9837]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"74334.flac","artist":null,"album":null,"uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac"} Apr 18 10:00:22 volumio volumio[9837]: verbose: CURRENT POSITION 0 Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState stateService play Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::syncState currentStatus play Apr 18 10:00:22 volumio volumio[9837]: info: Received an update from plugin. extracting info from payload Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: CoreStateMachine::pushState Apr 18 10:00:22 volumio volumio[9837]: debug: CoreStateMachine::getState Apr 18 10:00:22 volumio volumio[9837]: info: CoreCommandRouter::volumioPushState Apr 18 10:00:22 volumio volumio[9837]: debug: API:pushState Apr 18 10:00:22 volumio volumio[9837]: debug: No callbacks for volumioPushState Apr 18 10:00:22 volumio volumio[9837]: info: ------------------------------ 123ms Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222653 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Playback state cache: timestamp: 1744963222657 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: playback/playing {"status":"play","position":0,"title":"74334.flac","artist":null,"album":null,"albumart":"http://192.168.2.158:8200/AlbumArt/25994-74334.jpg","uri":"http://192.168.2.158:8200/MediaItems/74334.flac","trackType":"flac","seek":0,"duration":239,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"bitrate":null,"random":true,"repeat":true,"repeatSingle":false,"consume":true,"volume":80,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":false,"service":"mpd"} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 0 -> 0.00041841004184100416 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[0],"targets":[0.00041841004184100416],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 0 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 0 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control] [TrackService]: Updating position for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Updating hardware for fader: 1 -> 0.0008368200836820083 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Event triggered: fader/update {"indexes":[1],"targets":[0.0008368200836820083],"speeds":[100],"resolution":1} Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Stopping interval for service: 1 Apr 18 10:00:22 volumio volumio[9837]: debug: [motorized_fader_control]: Starting interval for service: 1 with 900ms interval Apr 18 10:00:22 volumio volumio[9837]: info: [motorized_fader_control] [TrackService]: Handling play state for fader: 1 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Apr 18 10:00:22 volumio volumio[9837]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 10:00:22 volumio volumio[9837]: ReferenceError: self is not defined Apr 18 10:00:22 volumio volumio[9837]: at motorizedFaderControl.processFaderMoveQueue (/data/plugins/system_hardware/motorized_fader_control/index.js:1010:30) Apr 18 10:00:22 volumio volumio[9837]: at Timeout. (/data/plugins/system_hardware/motorized_fader_control/index.js:954:18) Apr 18 10:00:22 volumio volumio[9837]: at listOnTimeout (internal/timers.js:554:17) Apr 18 10:00:22 volumio volumio[9837]: at processTimers (internal/timers.js:497:7) Apr 18 10:00:22 volumio volumio[9837]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 18 10:00:23 volumio sudo[10341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-18 09:59 Apr 18 10:00:23 volumio sudo[10341]: 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="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"