-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Fri 2024-10-18 17:38:28 CEST. -- Oct 18 17:37:00 volumio sudo[7293]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:00 volumio systemd[1]: volumio.service: Failed with result 'signal'. Oct 18 17:37:00 volumio systemd[1]: Started dynamicswap service. Oct 18 17:37:01 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 18 17:37:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Oct 18 17:37:01 volumio systemd[1]: Stopped Volumio Backend Module. Oct 18 17:37:01 volumio systemd[1]: Started Volumio Backend Module. Oct 18 17:37:01 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 18 17:37:05 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:05 volumio volumio[8687]: info: ----- Volumio3 ---- Oct 18 17:37:05 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:05 volumio volumio[8687]: info: ----- System startup ---- Oct 18 17:37:05 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:06 volumio kernel: hwmon hwmon1: Voltage normalised Oct 18 17:37:07 volumio volumio[8687]: info: MYVOLUMIO Environment detected Oct 18 17:37:07 volumio volumio[8687]: info: Plugin folders cleanup Oct 18 17:37:07 volumio volumio[8687]: info: Scanning into folder /volumio/app/plugins/ Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category audio_interface Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category miscellanea Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category music_service Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category plugins.json Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category system_controller Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category user_interface Oct 18 17:37:07 volumio volumio[8687]: info: Scanning into folder /data/plugins/ Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category audio_interface Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category music_service Oct 18 17:37:07 volumio volumio[8687]: info: Scanning category user_interface Oct 18 17:37:07 volumio volumio[8687]: info: Plugin folders cleanup completed Oct 18 17:37:07 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:07 volumio volumio[8687]: info: ----- Core plugins startup ---- Oct 18 17:37:07 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:07 volumio volumio[8687]: info: Loading plugins from folder /volumio/app/plugins/ Oct 18 17:37:07 volumio volumio[8687]: info: Adding plugin upnp to MyMusic Plugins Oct 18 17:37:07 volumio volumio[8687]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 18 17:37:07 volumio volumio[8687]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 18 17:37:07 volumio volumio[8687]: info: Loading plugins from folder /data/plugins/ Oct 18 17:37:07 volumio volumio[8687]: info: Loading plugin "system"... Oct 18 17:37:07 volumio volumio-remote-updater[657]: [2024-10-18 15:37:07] [connect] Successful connection Oct 18 17:37:07 volumio volumio[8687]: info: Loading plugin "appearance"... Oct 18 17:37:10 volumio volumio[8687]: info: Loading plugin "network"... Oct 18 17:37:10 volumio volumio[8687]: info: Refreshing Cached IP Addresses Oct 18 17:37:10 volumio volumio[8687]: info: Loading plugin "services"... Oct 18 17:37:10 volumio volumio[8687]: info: Loading plugin "alsa_controller"... Oct 18 17:37:10 volumio sudo[8770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:10 volumio sudo[8772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:10 volumio sudo[8770]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:10 volumio sudo[8772]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:10 volumio sudo[8772]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:10 volumio sudo[8770]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:10 volumio sudo[8774]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 18 17:37:10 volumio sudo[8774]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:11 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "wizard"... Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "networkfs"... Oct 18 17:37:11 volumio volumio[8687]: info: Starting Udev Watcher for removable devices Oct 18 17:37:11 volumio volumio[8687]: info: Ignoring mount for partition: boot Oct 18 17:37:11 volumio volumio[8687]: info: Ignoring mount for partition: volumio Oct 18 17:37:11 volumio volumio[8687]: info: Ignoring mount for partition: volumio_data Oct 18 17:37:11 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "volumio_command_line_client"... Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "upnp"... Oct 18 17:37:11 volumio volumio[8687]: info: [1729265831520] Starting Upmpd Daemon Oct 18 17:37:11 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "my_music"... Oct 18 17:37:11 volumio volumio[8687]: info: Loading plugin "mpd"... Oct 18 17:37:11 volumio sudo[8774]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:12 volumio volumio[8687]: info: Loading plugin "upnp_browser"... Oct 18 17:37:12 volumio volumio[8687]: info: Loading plugin "alarm-clock"... Oct 18 17:37:12 volumio volumio[8687]: info: Loading plugin "airplay_emulation"... Oct 18 17:37:12 volumio volumio[8687]: info: Starting Shairport Sync Oct 18 17:37:12 volumio volumio[8687]: info: Loading plugin "last_100"... Oct 18 17:37:12 volumio volumio[8687]: info: Loading plugin "webradio"... Oct 18 17:37:13 volumio volumio[8687]: info: Loading plugin "i2s_dacs"... Oct 18 17:37:13 volumio volumio[8687]: info: I2S DAC not set, start Auto-detection Oct 18 17:37:13 volumio volumio[8687]: info: Loading plugin "volumiodiscovery"... Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** For more information see Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 18 17:37:13 volumio volumio[8687]: *** WARNING *** For more information see Oct 18 17:37:13 volumio node[8687]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 18 17:37:13 volumio node[8687]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 18 17:37:13 volumio node[8687]: *** WARNING *** For more information see Oct 18 17:37:13 volumio node[8687]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 18 17:37:13 volumio node[8687]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 18 17:37:13 volumio node[8687]: *** WARNING *** For more information see Oct 18 17:37:13 volumio volumio[8687]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 18 17:37:13 volumio volumio[8687]: info: Discovery: Started advertising with name: Volumio Oct 18 17:37:13 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 18 17:37:13 volumio volumio[8687]: info: Loading plugin "spop"... Oct 18 17:37:15 volumio volumio[8687]: info: Plugin now_playing is not enabled Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "outputs"... Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "albumart"... Oct 18 17:37:15 volumio volumio[8687]: info: Plugin example_plugin is not enabled Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "inputs"... Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "updater_comm"... Oct 18 17:37:15 volumio volumio[8687]: info: Plugin mpdemulation is not enabled Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "rest_api"... Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "websocket"... Oct 18 17:37:15 volumio volumio[8687]: info: Starting Socket.io Server version 2.3.0 Oct 18 17:37:15 volumio volumio[8687]: info: Loading plugin "fusiondsp"... Oct 18 17:37:15 volumio volumio[8687]: Forking 3 albumart workers Oct 18 17:37:16 volumio volumio[8687]: info: Applying required configuration parameters for plugin fusiondsp Oct 18 17:37:16 volumio volumio[8687]: info: Plugin touch_display is not enabled Oct 18 17:37:16 volumio volumio[8687]: info: Loading i18n strings for locale nl Oct 18 17:37:16 volumio volumio[8687]: Updating browse sources language Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::initPlayerControls Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: Starting albumart workers Oct 18 17:37:16 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 17:37:16 volumio volumio[8687]: Express server listening on port 3000 Oct 18 17:37:16 volumio volumio[8687]: [Metrics] WebUI: 12s 108.96ms Oct 18 17:37:16 volumio volumio[8687]: Starting albumart workers Oct 18 17:37:16 volumio volumio[8687]: Starting albumart workers Oct 18 17:37:17 volumio volumio[8687]: info: CoreStateMachine::resetVolumioState Oct 18 17:37:17 volumio volumio[8687]: info: CoreStateMachine::getcurrentVolume Oct 18 17:37:17 volumio volumio[8687]: info: CoreCommandRouter::volumioRetrievevolume Oct 18 17:37:17 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 18 17:37:17 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:17 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.51 from 192.168.1.18 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 1 Oct 18 17:37:17 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.11 from 192.168.1.18 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: Reloading queue from file Oct 18 17:37:18 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:18 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetVisibleSources Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 18 17:37:18 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:18 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: Listing playlists Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:18 volumio volumio[8687]: info: VolumeController:: Volume=86 Mute =false Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::updateTrackBlock Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrackBlock Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioRetrievevolume Oct 18 17:37:18 volumio volumio[8687]: info: Setting Device type: Raspberry PI Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::setRepeat null single undefined Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::setRandom null Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:18 volumio volumio[8687]: info: VolumeController:: Volume=86 Mute =false Oct 18 17:37:18 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:18 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:18 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:19 volumio volumio[8687]: info: Discovery: adding 0b6a6d87-d25f-4ec5-ad1c-b3044fb235a9 Oct 18 17:37:19 volumio volumio[8687]: info: Discovery: Found device Volumio Oct 18 17:37:19 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:19 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:19 volumio volumio[8687]: info: Discovery: this is already registered, 0b6a6d87-d25f-4ec5-ad1c-b3044fb235a9 Oct 18 17:37:19 volumio volumio[8687]: info: Discovery: Found device Volumio Oct 18 17:37:19 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:19 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:19 volumio volumio[8687]: info: Completed loading Core Plugins Oct 18 17:37:19 volumio volumio[8687]: info: Preparing to generate the ALSA configuration file Oct 18 17:37:20 volumio volumio[8687]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 18 17:37:20 volumio volumio[8687]: info: Reading ALSA contributions from plugins. Oct 18 17:37:20 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:21 volumio volumio[8687]: info: Asound.conf file unchanged, so no further update is needed Oct 18 17:37:21 volumio volumio[8687]: info: Output device has changed, restarting MPD Oct 18 17:37:21 volumio sudo[8852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 18 17:37:21 volumio sudo[8852]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:21 volumio volumio[8687]: info: Output device has changed, restarting Shairport Sync Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:21 volumio sudo[8852]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:21 volumio sudo[8854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 18 17:37:21 volumio sudo[8854]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:21 volumio volumio[8687]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 18 17:37:21 volumio volumio[8687]: info: ___________ START PLUGINS ___________ Oct 18 17:37:21 volumio volumio[8687]: info: ControllerMpd::onStart: Initializing MPD Oct 18 17:37:21 volumio volumio[8687]: info: Creating MPD Configuration file Oct 18 17:37:21 volumio systemd[1]: Stopping Music Player Daemon... Oct 18 17:37:21 volumio sudo[8861]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 18 17:37:21 volumio sudo[8861]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:21 volumio sudo[8861]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 18 17:37:21 volumio volumio[8687]: info: [1729265841439] CoreMusicLibrary::Adding element Media Servers Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:21 volumio sudo[8864]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 18 17:37:21 volumio sudo[8864]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:21 volumio volumio[8687]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 18 17:37:21 volumio volumio[8687]: info: [1729265841773] CoreMusicLibrary::Adding element Last_100 Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 18 17:37:21 volumio volumio[8687]: info: [1729265841782] CoreMusicLibrary::Adding element Webradio Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:37:21 volumio volumio[8687]: info: Initializing BBC Radios Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:37:21 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:22 volumio volumio[8687]: info: Creating Spotify config file Oct 18 17:37:22 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:22 volumio volumio[8687]: info: Loading i18n strings for locale nl Oct 18 17:37:22 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 18 17:37:22 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:22 volumio volumio[8687]: info: FusionDsp - mixtype--------------------- Hardware Oct 18 17:37:22 volumio volumio[8687]: info: Volumio Calling Home Oct 18 17:37:22 volumio volumio-remote-updater[657]: [2024-10-18 15:37:22] [connect] Successful connection Oct 18 17:37:22 volumio volumio[8687]: info: Preparing to generate the ALSA configuration file Oct 18 17:37:22 volumio volumio[8687]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 18 17:37:22 volumio volumio[8687]: info: Reading ALSA contributions from plugins. Oct 18 17:37:22 volumio sudo[8887]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:22 volumio sudo[8887]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:22 volumio sudo[8889]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:22 volumio sudo[8889]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:22 volumio sudo[8889]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:22 volumio sudo[8887]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:22 volumio volumio[8687]: info: MPD Permissions set Oct 18 17:37:22 volumio volumio[8687]: info: MPD Permissions set Oct 18 17:37:22 volumio volumio-remote-updater[657]: [2024-10-18 15:37:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729265842 101 Oct 18 17:37:22 volumio volumio[8687]: 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: 3 Oct 18 17:37:23 volumio volumio[8687]: info: Spotify config file written Oct 18 17:37:23 volumio sudo[8893]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 18 17:37:23 volumio sudo[8893]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:23 volumio systemd[1]: Stopping go-librespot Daemon... Oct 18 17:37:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Oct 18 17:37:23 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Oct 18 17:37:23 volumio systemd[1]: Stopped go-librespot Daemon. Oct 18 17:37:23 volumio systemd[1]: Started go-librespot Daemon. Oct 18 17:37:23 volumio go-librespot[8895]: Librespot-go daemon starting... Oct 18 17:37:23 volumio sudo[8893]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:23 volumio volumio[8687]: error: error Oct 18 17:37:23 volumio volumio[8687]: error: error Oct 18 17:37:23 volumio go-librespot[8895]: time="2024-10-18T17:37:23+02:00" level=info msg="generated new device id: 580b979017aab6164459b1c42a872eb8460eebd7" Oct 18 17:37:23 volumio go-librespot[8895]: time="2024-10-18T17:37:23+02:00" level=debug msg="stored credentials found for 31ppk25faiijd23ke22ghdllddui" Oct 18 17:37:23 volumio volumio[8687]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio volumio[8687]: info: No need to fix Spotify hosts Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=debug msg="zeroconf server listening on port 44775" Oct 18 17:37:24 volumio volumio[8687]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Oct 18 17:37:24 volumio volumio[8687]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Oct 18 17:37:24 volumio volumio[8687]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Oct 18 17:37:24 volumio volumio[8687]: info: camilladsp spawned new process with pid 8923, instance 1, run: true Oct 18 17:37:24 volumio volumio[8687]: info: camilladsp service started and running in background, instance 1 Oct 18 17:37:24 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=debug msg="obtained new client token: AAAeXY8JAmex8VogXF6XapOhkNJRv3h++MgGQFi/rlzhlwERfra9iZF+wltW32/BVsBWoI2C7BoyHUY5y7/W4coHfflueACMcJ5uwZTK3yee/k5+h1867Ha3Fmvy0WmKTWP2kD+2LSvmvF2NQylJMj5+Zn0wPyqw9o2SP2gCz5q0WlSU+WwOJeQz4qhKTmT/cONT4STmoXtL9iZewuF1mcyL9EChpx/oygW6WyfbjbNt3XfBeAzKE7UbWV4fj8U=" Oct 18 17:37:24 volumio go-librespot[8895]: time="2024-10-18T17:37:24+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 18 17:37:25 volumio volumio[8687]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Oct 18 17:37:25 volumio volumio[8687]: info: FusionDsp loaded Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="completed keyexchange" Oct 18 17:37:25 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:25 volumio systemd[1]: mpd.service: Succeeded. Oct 18 17:37:25 volumio systemd[1]: Stopped Music Player Daemon. Oct 18 17:37:25 volumio sudo[8929]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 18 17:37:25 volumio sudo[8929]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio volumio[8687]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 18 17:37:25 volumio volumio[8687]: info: Adding Signal Path Element [object Object] Oct 18 17:37:25 volumio volumio[8687]: info: Adding fusiondspeq DSP Signal Path Element Oct 18 17:37:25 volumio systemd[1]: Starting Music Player Daemon... Oct 18 17:37:25 volumio volumio[8687]: info: FusionDsp - ---- installed callbackRead Oct 18 17:37:25 volumio volumio[8687]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 18 17:37:25 volumio sudo[8929]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:25 volumio volumio[8687]: info: Volumio called home Oct 18 17:37:25 volumio volumio[8687]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 18 17:37:25 volumio volumio[8687]: SPOTIFY: BQA0zpf90yCvZ3Y8Ws_ED_30TFSbJbXHVu7_bnCizOph6l8bbP3BwRfsgWHEKj8mqvTs7V909Eh_VPNtGKqJUW_fFtcy8fv9zdZtGrfj95akNvVtJSXrYy8bsNCzVgE21dCYIJiVhcdkedd5Ixnz36cGbFLV4F_aTAPcWxsZF48v1GzpkkLHyDD8pZrwvB5T5GXzDaBHcOE5HWozm_XgB82pna1nzei4lhNwCYa3O6eYmeZQ5griWjqGEovUYScCbVuM_DB7DwkevTC2nDg Oct 18 17:37:25 volumio volumio[8687]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 18 17:37:25 volumio volumio[8687]: info: New Spotify access token = BQA0zpf90yCvZ3Y8Ws_ED_30TFSbJbXHVu7_bnCizOph6l8bbP3BwRfsgWHEKj8mqvTs7V909Eh_VPNtGKqJUW_fFtcy8fv9zdZtGrfj95akNvVtJSXrYy8bsNCzVgE21dCYIJiVhcdkedd5Ixnz36cGbFLV4F_aTAPcWxsZF48v1GzpkkLHyDD8pZrwvB5T5GXzDaBHcOE5HWozm_XgB82pna1nzei4lhNwCYa3O6eYmeZQ5griWjqGEovUYScCbVuM_DB7DwkevTC2nDg Oct 18 17:37:25 volumio volumio[8687]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 18 17:37:25 volumio sudo[8930]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 18 17:37:25 volumio sudo[8930]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio sudo[8930]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:25 volumio volumio[8687]: info: Starting Shairport Sync Oct 18 17:37:25 volumio sudo[8941]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 18 17:37:25 volumio sudo[8941]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="completed challenge" Oct 18 17:37:25 volumio volumio[8687]: info: Starting Shairport Sync Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="authenticated as 31ppk25faiijd23ke22ghdllddui" Oct 18 17:37:25 volumio volumio[8687]: info: Starting Shairport Sync Oct 18 17:37:25 volumio sudo[8941]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:25 volumio sudo[8943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 18 17:37:25 volumio sudo[8943]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio sudo[8947]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 18 17:37:25 volumio sudo[8947]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="authenticated as 31ppk25faiijd23ke22ghdllddui" Oct 18 17:37:25 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 18 17:37:25 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:25 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:25 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:25 volumio sudo[8949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 18 17:37:25 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:25 volumio sudo[8943]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:25 volumio sudo[8949]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="dealer connection opened" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="initializing zeroconf session, username: 31ppk25faiijd23ke22ghdllddui" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="autoplay enabled: false" Oct 18 17:37:25 volumio go-librespot[8895]: time="2024-10-18T17:37:25+02:00" level=debug msg="received connection id: ZjQzYjU1OWUtMzM5ZC00NzQ4LTgxNjYtZGM0MGQwODUyYmM4K2RlYWxlcit0Y3A6Ly8wYWNhNTg5YS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNkM0QzNFMEJBMjVGQkQ2NTQ4OURFMUQ2NEZGNzc4MDMyQTcxNEI2MjRCQzFBOEM4NEE0OEUwREM5QkYxRkI3OA==" Oct 18 17:37:25 volumio volumio[8687]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Oct 18 17:37:25 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 18 17:37:26 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 18 17:37:26 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:26 volumio go-librespot[8895]: time="2024-10-18T17:37:26+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 18 17:37:26 volumio volumio[8687]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 18 17:37:26 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:26 volumio sudo[8947]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:26 volumio sudo[8949]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:26 volumio volumio[8687]: info: Shairport-Sync Started Oct 18 17:37:26 volumio volumio[8687]: Error adding Membership: Error: addMembership EINVAL Oct 18 17:37:26 volumio volumio[8687]: info: Upmpdcli Daemon Started Oct 18 17:37:26 volumio volumio[8687]: info: Asound.conf file unchanged, so no further update is needed Oct 18 17:37:26 volumio volumio[8687]: info: Output device has changed, restarting MPD Oct 18 17:37:26 volumio sudo[8959]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 18 17:37:26 volumio sudo[8959]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:26 volumio volumio[8687]: info: Output device has changed, restarting Shairport Sync Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:26 volumio sudo[8959]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:26 volumio sudo[8961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 18 17:37:26 volumio sudo[8961]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:26 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 18 17:37:26 volumio systemd[1]: mpd.service: Succeeded. Oct 18 17:37:26 volumio systemd[1]: Stopped Music Player Daemon. Oct 18 17:37:26 volumio volumio[8687]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 18 17:37:26 volumio systemd[1]: Starting Music Player Daemon... Oct 18 17:37:26 volumio volumio[8687]: info: Shairport-Sync Started Oct 18 17:37:26 volumio volumio[8687]: info: Shairport-Sync Started Oct 18 17:37:26 volumio volumio[8687]: info: MPD Permissions set Oct 18 17:37:26 volumio sudo[8967]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 18 17:37:26 volumio sudo[8967]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:26 volumio sudo[8967]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:26 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:27 volumio volumio[8687]: SPOTIFY: User informations: {"country":"NL","display_name":"jelle van den heuvel","email":"jelle.heuvel.2012@outlook.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/31ppk25faiijd23ke22ghdllddui"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/31ppk25faiijd23ke22ghdllddui","id":"31ppk25faiijd23ke22ghdllddui","images":[{"height":300,"url":"https://i.scdn.co/image/ab6775700000ee856c9322fcd6730105fc729e0b","width":300},{"height":64,"url":"https://i.scdn.co/image/ab67757000003b826c9322fcd6730105fc729e0b","width":64}],"product":"premium","type":"user","uri":"spotify:user:31ppk25faiijd23ke22ghdllddui"} Oct 18 17:37:27 volumio volumio[8687]: info: Spotify Successfully logged in Oct 18 17:37:27 volumio volumio[8687]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 18 17:37:27 volumio volumio[8687]: info: [1729265847129] CoreMusicLibrary::Adding element Spotify Oct 18 17:37:27 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:27 volumio volumio[8687]: Cannot find translation for source Spotify Oct 18 17:37:27 volumio volumio[8687]: info: Starting Shairport Sync Oct 18 17:37:27 volumio sudo[8977]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 18 17:37:27 volumio sudo[8977]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:27 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 18 17:37:27 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 18 17:37:27 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:27 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 18 17:37:27 volumio sudo[8977]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:27 volumio volumio[8687]: info: Shairport-Sync Started Oct 18 17:37:27 volumio volumio[8687]: info: go-librespot daemon successfully initialized Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=debug msg="handling transfer player command from 72c2f9723d5b09ec83a86ef9a22056a5f6fdb3d4" Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=debug msg="resolved context of track" uri="spotify:album:5ZCo1wqpAvjgHieipwTXzZ" Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=trace msg="fetched new page 0 with 34 items (list: 34)" uri="spotify:album:5ZCo1wqpAvjgHieipwTXzZ" Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=debug msg="loading track (paused: true, position: 60113ms)" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:27 volumio go-librespot[8895]: time="2024-10-18T17:37:27+02:00" level=trace msg="emitting websocket event: will_play" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="selected format OGG_VORBIS_320 (0e33ad38245c1669c4b7205ca88f6feea74a05fb)" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="requested aes key for file 0e33ad38245c1669c4b7205ca88f6feea74a05fb, gid: 54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1326" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="fetched first chunk of 20, total size is 10034156 bytes" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:28 volumio go-librespot[8895]: time="2024-10-18T17:37:28+02:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio sudo[8985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:29 volumio sudo[8985]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:29 volumio sudo[8987]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:29 volumio sudo[8987]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:29 volumio sudo[8985]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:29 volumio sudo[8987]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:29 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.145 from 192.168.1.141 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) CriOS/129.0.6668.69 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 6 Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=trace msg="seek to 60113ms (diff: 30ms, samples: 2650983, bytes: 2472888)" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::volumioGetVisibleSources Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:29 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 18 17:37:29 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:29 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:29 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:29 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:29 volumio volumio[8687]: info: Listing playlists Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 18 17:37:29 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="created new output device" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=info msg="loaded track \"NIGHT RUNNING\" (paused: true, position: 60113ms, duration: 233666ms, prefetched: false)" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=trace msg="emitting websocket event: metadata" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=trace msg="emitting websocket event: active" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="sending successful reply for dealer request" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Oct 18 17:37:29 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 18 17:37:29 volumio volumio[8687]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 18 17:37:29 volumio volumio[8687]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 18 17:37:29 volumio volumio[8687]: info: camilladsp stopping service pid 8923... Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:29 volumio go-librespot[8895]: time="2024-10-18T17:37:29+02:00" level=trace msg="emitting websocket event: paused" Oct 18 17:37:29 volumio volumio[8687]: info: camilladsp service terminated, instance 1 Oct 18 17:37:29 volumio volumio[8687]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 18 17:37:29 volumio volumio[8687]: info: camilladsp service started and running in background, instance 1 Oct 18 17:37:29 volumio volumio[8687]: info: camilladsp spawned new process with pid 8993, instance 1, run: true Oct 18 17:37:29 volumio mpd[8971]: Oct 18 17:37 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 18 17:37:29 volumio systemd[1]: Started Music Player Daemon. Oct 18 17:37:29 volumio sudo[8961]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:29 volumio sudo[8854]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:29 volumio sudo[8864]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:29 volumio volumio[8687]: info: Completed starting Core Plugins Oct 18 17:37:29 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:29 volumio volumio[8687]: info: ----- MyVolumio plugins startup ---- Oct 18 17:37:29 volumio volumio[8687]: info: ------------------------------------------- Oct 18 17:37:29 volumio volumio[8687]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 18 17:37:29 volumio volumio[8687]: info: MPD running with PID8971 Oct 18 17:37:29 volumio volumio[8687]: ,establishing connection Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=debug msg="handling resume player command from 72c2f9723d5b09ec83a86ef9a22056a5f6fdb3d4" Oct 18 17:37:30 volumio volumio[8687]: error: MPD error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio volumio[8687]: error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio volumio[8687]: error: MPD error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio volumio[8687]: error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio volumio[8687]: error: MPD error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio volumio[8687]: error: The expression evaluated to a falsy value: Oct 18 17:37:30 volumio volumio[8687]: assert.ok(self.idling) Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=trace msg="seek to 60113ms (diff: 30ms, samples: 2650983, bytes: 2472888)" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=debug msg="resume track at 60079ms" Oct 18 17:37:30 volumio sudo[9006]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:30 volumio sudo[9006]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=trace msg="scheduling prefetch in 144s" Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=debug msg="sending successful reply for dealer request" Oct 18 17:37:30 volumio volumio[8687]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 18 17:37:30 volumio volumio[8687]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 18 17:37:30 volumio volumio[8687]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 18 17:37:30 volumio sudo[9006]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:30 volumio volumio[8687]: error: updateQueue error: null Oct 18 17:37:30 volumio sudo[9009]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:30 volumio sudo[9009]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:30 volumio volumio[8687]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:30 volumio go-librespot[8895]: time="2024-10-18T17:37:30+02:00" level=trace msg="emitting websocket event: playing" Oct 18 17:37:30 volumio sudo[9009]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:30 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.145 from 192.168.1.141 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) CriOS/129.0.6668.69 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 6 Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::volumioGetVisibleSources Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:30 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 18 17:37:30 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:30 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:30 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:30 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:30 volumio volumio[8687]: info: Listing playlists Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 18 17:37:30 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:31 volumio volumio[8687]: info: Initializing connection to go-librespot Websocket Oct 18 17:37:31 volumio go-librespot[8895]: time="2024-10-18T17:37:31+02:00" level=debug msg="new websocket client" Oct 18 17:37:31 volumio volumio[8687]: info: Connection to go-librespot Websocket established Oct 18 17:37:31 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 18 17:37:31 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:31 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:31 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:31 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:31 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:31 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:31 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:32 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 18 17:37:32 volumio go-librespot[8895]: time="2024-10-18T17:37:32+02:00" level=debug msg="fetched chunk 8/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:33 volumio kernel: hwmon hwmon1: Voltage normalised Oct 18 17:37:34 volumio volumio[8687]: info: Getting Spotify volume Oct 18 17:37:34 volumio volumio[8687]: info: Spotify volume: 100 Oct 18 17:37:34 volumio volumio[8687]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 18 17:37:34 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:34 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:34 volumio volumio[8687]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 18 17:37:34 volumio volumio[8687]: SPOTIFY: SPOTIFY VOLUME 100 Oct 18 17:37:34 volumio volumio[8687]: SPOTIFY: VOLUMIO VOLUME 86 Oct 18 17:37:34 volumio volumio[8687]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 18 17:37:34 volumio volumio[8687]: info: Setting Spotify Volume from Volumio: 86 Oct 18 17:37:34 volumio volumio[8687]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 18 17:37:36 volumio volumio[8687]: SPOTIFY: SETTING SPOTIFY VOLUME 86 Oct 18 17:37:36 volumio volumio[8687]: info: Sending Spotify command with payload to local API: /player/volume Oct 18 17:37:36 volumio go-librespot[8895]: time="2024-10-18T17:37:36+02:00" level=debug msg="update volume to 56360/65535" Oct 18 17:37:36 volumio go-librespot[8895]: time="2024-10-18T17:37:36+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 18 17:37:36 volumio go-librespot[8895]: time="2024-10-18T17:37:36+02:00" level=trace msg="emitting websocket event: volume" Oct 18 17:37:36 volumio volumio[8687]: SPOTIFY: received: {"type":"volume","data":{"value":86,"max":100}} Oct 18 17:37:36 volumio volumio[8687]: SPOTIFY: RECEIVED SPOTIFY VOLUME 86 Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin bluetooth to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin multiroom to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin metavolumio to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin cd_controller to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 18 17:37:38 volumio volumio[8687]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 18 17:37:39 volumio volumio[8687]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 18 17:37:39 volumio volumio[8687]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 18 17:37:39 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:39 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:39 volumio volumio[8687]: info: Starting MyVolumio Remote Streaming Endpoints Oct 18 17:37:39 volumio volumio[8687]: info: MyVolumio login type: Token Oct 18 17:37:39 volumio volumio[8687]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 18 17:37:39 volumio volumio[8687]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 18 17:37:41 volumio volumio[8687]: info: Starting Streaming Service Transparent Proxy Oct 18 17:37:41 volumio volumio[8687]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 18 17:37:41 volumio volumio[8687]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 18 17:37:41 volumio volumio[8687]: info: Streaming services startup Oct 18 17:37:41 volumio volumio[8687]: info: Starting Streaming Daemon Oct 18 17:37:41 volumio sudo[9021]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 18 17:37:41 volumio sudo[9021]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:41 volumio volumio[8687]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 18 17:37:41 volumio sudo[9021]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:41 volumio volumio[8687]: error: Cannot start Volumio Streaming Daemon Oct 18 17:37:41 volumio volumio[8687]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 18 17:37:41 volumio volumio[8687]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:41 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:41 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:41 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:41 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:41 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.11:3000 from 192.168.1.141 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:41 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 18 17:37:41 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 18 17:37:42 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 18 17:37:42 volumio volumio[8687]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:42 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:42 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:42 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:42 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:42 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:43 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:43 volumio volumio[8687]: STREAMING PROXY: Starting server on port 3245 Oct 18 17:37:43 volumio volumio[8687]: Node JS runtime: 14 Oct 18 17:37:44 volumio sudo[9032]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:44 volumio sudo[9032]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:44 volumio volumio[8687]: info: MyVolumio token set successfully Oct 18 17:37:44 volumio volumio[8687]: info: MYVOLUMIO: Adding device Oct 18 17:37:44 volumio volumio[8687]: info: MYVOLUMIO: Evaluating Server Oct 18 17:37:44 volumio sudo[9032]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:44 volumio sudo[9034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:44 volumio sudo[9034]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:44 volumio sudo[9034]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:44 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.145 from 192.168.1.141 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Oct 18 17:37:44 volumio go-librespot[8895]: time="2024-10-18T17:37:44+02:00" level=debug msg="fetched chunk 9/19, size: 524288" uri="spotify:track:54BW4qpq5ms4bnzBgiWVOo" Oct 18 17:37:44 volumio volumio[8687]: info: MyVolumio status changed Oct 18 17:37:44 volumio volumio[8687]: info: Streaming services startup Oct 18 17:37:44 volumio volumio[8687]: info: Starting Streaming Daemon Oct 18 17:37:44 volumio volumio[8687]: info: Removing browser output: myVolumio user plan is not superstar Oct 18 17:37:44 volumio volumio[8687]: info: Removing audio output: Oct 18 17:37:44 volumio volumio[8687]: info: Stoppping Tunnel 1 Oct 18 17:37:45 volumio sudo[9053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 18 17:37:45 volumio sudo[9053]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:45 volumio sudo[9056]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 18 17:37:45 volumio sudo[9053]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:45 volumio sudo[9056]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:45 volumio volumio[8687]: error: Cannot start Volumio Streaming Daemon Oct 18 17:37:45 volumio volumio[8687]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 18 17:37:45 volumio volumio[8687]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 18 17:37:45 volumio sudo[9056]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 18 17:37:45 volumio volumio[8687]: info: Remote SSH Stopped Oct 18 17:37:45 volumio volumio[8687]: info: Setting Geolocation for MyVolumio to eu5 Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:45 volumio sudo[9059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 18 17:37:45 volumio sudo[9059]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:45 volumio sudo[9059]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:45 volumio sudo[9062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 18 17:37:45 volumio sudo[9062]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 17:37:45 volumio sudo[9062]: pam_unix(sudo:session): session closed for user root Oct 18 17:37:45 volumio volumio[8687]: verbose: New Socket.io Connection to 192.168.1.145 from 192.168.1.141 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_0 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::volumioGetVisibleSources Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:45 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 18 17:37:45 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:45 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:45 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:45 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:45 volumio volumio[8687]: info: Listing playlists Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 18 17:37:45 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:46 volumio volumio[8687]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 18 17:37:46 volumio volumio[8687]: info: Updating MyVolumio device info Oct 18 17:37:46 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:46 volumio volumio[8687]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 18 17:37:47 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:47 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:47 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:47 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:48 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 18 17:37:48 volumio volumio[8687]: info: Received Get System Info Oct 18 17:37:48 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:37:48 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:37:48 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:37:48 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:48 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:48 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:37:48 volumio kernel: hwmon hwmon1: Voltage normalised Oct 18 17:37:50 volumio volumio[8687]: info: MYVOLUMIO: Adding device Oct 18 17:37:50 volumio volumio[8687]: info: MYVOLUMIO: Evaluating Server Oct 18 17:37:50 volumio volumio[8687]: info: Setting Geolocation for MyVolumio to eu2 Oct 18 17:37:50 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:50 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:50 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:51 volumio volumio[8687]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 18 17:37:51 volumio volumio[8687]: info: Updating MyVolumio device info Oct 18 17:37:51 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:51 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:51 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:52 volumio volumio[8687]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::volumioPlay Oct 18 17:37:52 volumio volumio[8687]: info: CoreStateMachine::play index undefined Oct 18 17:37:52 volumio volumio[8687]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 18 17:37:52 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:52 volumio volumio[8687]: info: CoreStateMachine::startPlaybackTimer Oct 18 17:37:52 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:52 volumio volumio[8687]: info: [1729265872245] ControllerSpotify::clearAddPlayTrack Oct 18 17:37:52 volumio volumio[8687]: info: Sending Spotify command with payload to local API: /player/play Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="resolved context of track" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="emitting websocket event: will_play" Oct 18 17:37:52 volumio volumio[8687]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","play_origin":"go-librespot"}} Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="selected format OGG_VORBIS_320 (b88cada6b65e855c70166666d485d567b7fa1258)" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="requested aes key for file b88cada6b65e855c70166666d485d567b7fa1258, gid: 63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio volumio-remote-updater[657]: No test mode Oct 18 17:37:52 volumio volumio-remote-updater[657]: No alpha test mode Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 18 17:37:52 volumio volumio[8687]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="fetched first chunk of 17, total size is 8587190 bytes" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=info msg="loaded track \"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)\" (paused: false, position: 0ms, duration: 201875ms, prefetched: false)" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="scheduling prefetch in 172s" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="emitting websocket event: metadata" Oct 18 17:37:52 volumio volumio[8687]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","name":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist_names":["SAWTOWNE","Hatsune Miku"],"album_name":"M@GICAL CURE! LOVE SHOT!","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","position":0,"duration":201875,"release_date":"year:2024 month:3 day:19","track_number":1,"disc_number":1}} Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=trace msg="emitting websocket event: playing" Oct 18 17:37:52 volumio volumio[8687]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","play_origin":"go-librespot"}} Oct 18 17:37:52 volumio volumio[8687]: SPOTIFY: PUSH STATE SPOTIFY Oct 18 17:37:52 volumio volumio[8687]: SPOTIFY: {"status":"play","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":0,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:52 volumio volumio[8687]: info: CoreCommandRouter::servicePushState Oct 18 17:37:52 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:52 volumio volumio[8687]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":0,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:52 volumio volumio[8687]: verbose: CURRENT POSITION 0 Oct 18 17:37:52 volumio volumio[8687]: info: CoreStateMachine::syncState stateService play Oct 18 17:37:52 volumio volumio[8687]: info: CoreStateMachine::syncState currentStatus stop Oct 18 17:37:52 volumio go-librespot[8895]: time="2024-10-18T17:37:52+02:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:63yoRZd5zl6Ah30hfDm97k" Oct 18 17:37:53 volumio volumio[8687]: SPOTIFY: PUSH STATE SPOTIFY Oct 18 17:37:53 volumio volumio[8687]: SPOTIFY: {"status":"play","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":0,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:53 volumio volumio[8687]: info: CoreCommandRouter::servicePushState Oct 18 17:37:53 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:53 volumio volumio[8687]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":0,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:53 volumio volumio[8687]: verbose: CURRENT POSITION 0 Oct 18 17:37:53 volumio volumio[8687]: info: CoreStateMachine::syncState stateService play Oct 18 17:37:53 volumio volumio[8687]: info: CoreStateMachine::syncState currentStatus play Oct 18 17:37:53 volumio volumio[8687]: info: Received an update from plugin. extracting info from payload Oct 18 17:37:53 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:53 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:53 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 18 17:37:53 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:53 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:53 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:53 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:53 volumio volumio[8687]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 18 17:37:53 volumio volumio[8687]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 18 17:37:54 volumio volumio[8687]: info: CoreCommandRouter::volumioPause Oct 18 17:37:54 volumio volumio[8687]: info: CoreStateMachine::pause Oct 18 17:37:54 volumio volumio[8687]: info: CoreStateMachine::stPlaybackTimer Oct 18 17:37:54 volumio volumio[8687]: info: CoreStateMachine::servicePause Oct 18 17:37:54 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:54 volumio volumio[8687]: info: CoreCommandRouter::servicePause Oct 18 17:37:54 volumio volumio[8687]: info: Spotify Received pause Oct 18 17:37:54 volumio volumio[8687]: SPOTIFY: SPOTIFY PAUSE Oct 18 17:37:54 volumio volumio[8687]: SPOTIFY: {"status":"play","position":0,"title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d0000b273a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","codec":"ogg","seek":0,"duration":201,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":86,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Oct 18 17:37:54 volumio volumio[8687]: info: Sending Spotify command to local API: /player/pause Oct 18 17:37:54 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 18 17:37:54 volumio volumio[8687]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 18 17:37:54 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:37:54 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:54 volumio go-librespot[8895]: time="2024-10-18T17:37:54+02:00" level=debug msg="pause track at 2300ms" Oct 18 17:37:55 volumio go-librespot[8895]: time="2024-10-18T17:37:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:55 volumio go-librespot[8895]: time="2024-10-18T17:37:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 18 17:37:55 volumio go-librespot[8895]: time="2024-10-18T17:37:55+02:00" level=trace msg="emitting websocket event: paused" Oct 18 17:37:55 volumio volumio[8687]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","play_origin":"go-librespot"}} Oct 18 17:37:55 volumio volumio[8687]: SPOTIFY: PUSH STATE SPOTIFY Oct 18 17:37:55 volumio volumio[8687]: SPOTIFY: {"status":"pause","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":2000,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:55 volumio volumio[8687]: info: CoreCommandRouter::servicePushState Oct 18 17:37:55 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:55 volumio volumio[8687]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"M@GICAL CURE! LOVE SHOT! (feat. Hatsune Miku)","artist":"SAWTOWNE, Hatsune Miku","album":"M@GICAL CURE! LOVE SHOT!","albumart":"https://i.scdn.co/image/ab67616d00001e02a2f3d4936b6f398d90949081","uri":"spotify:track:63yoRZd5zl6Ah30hfDm97k","trackType":"spotify","seek":2000,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Oct 18 17:37:55 volumio volumio[8687]: verbose: CURRENT POSITION 0 Oct 18 17:37:55 volumio volumio[8687]: info: CoreStateMachine::syncState stateService pause Oct 18 17:37:55 volumio volumio[8687]: info: CoreStateMachine::syncState currentStatus pause Oct 18 17:37:55 volumio volumio[8687]: info: CoreStateMachine::pushState Oct 18 17:37:55 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:37:55 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 18 17:37:55 volumio volumio[8687]: info: CoreCommandRouter::volumioPushState Oct 18 17:37:55 volumio volumio[8687]: info: CoreStateMachine::stPlaybackTimer Oct 18 17:37:55 volumio volumio[8687]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Oct 18 17:37:55 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 18 17:37:55 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 18 17:37:55 volumio volumio[8687]: info: camilladsp spawned new process with pid 9085, instance 1, run: true Oct 18 17:37:57 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 18 17:37:57 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 18 17:37:57 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::volumioGetBrowseSources Oct 18 17:37:59 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:38:01 volumio volumio[8687]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 18 17:38:01 volumio volumio[8687]: info: Completed starting MyVolumio Plugin Oct 18 17:38:01 volumio volumio[8687]: info: BOOT COMPLETED Oct 18 17:38:01 volumio volumio[8687]: [Metrics] CommandRouter: 55s 593.23ms Oct 18 17:38:01 volumio volumio[8687]: info: CoreCommandRouter::volumiosetStartupVolume Oct 18 17:38:01 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 17:38:01 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 17:38:01 volumio volumio[8687]: info: CoreCommandRouter::Close All Modals sent Oct 18 17:38:01 volumio volumio[8687]: info: CoreCommandRouter::Close All Modals sent Oct 18 17:38:01 volumio volumio[8687]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 18 17:38:01 volumio volumio[8687]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 18 17:38:01 volumio volumio[8687]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 18 17:38:01 volumio volumio[8687]: info: FusionDsp - {"Reload":{"result":"Ok"}} Oct 18 17:38:02 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 18 17:38:02 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 18 17:38:02 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 18 17:38:03 volumio volumio[8687]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 18 17:38:03 volumio volumio[8687]: info: Received Get System Version Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 18 17:38:03 volumio volumio[8687]: info: Received Get System Info Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:38:03 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:38:03 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:38:03 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:38:04 volumio volumio[8687]: info: Enabling plugin now_playing Oct 18 17:38:04 volumio volumio[8687]: info: Loading plugin "now_playing"... Oct 18 17:38:04 volumio volumio[8687]: error: !!!! WARNING !!!! Oct 18 17:38:04 volumio volumio[8687]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Oct 18 17:38:04 volumio volumio[8687]: Require stack: Oct 18 17:38:04 volumio volumio[8687]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/app/pluginmanager.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/app/index.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/index.js Oct 18 17:38:04 volumio volumio[8687]: error: Stack trace: Error: Cannot find module 'geo-tz' Oct 18 17:38:04 volumio volumio[8687]: Require stack: Oct 18 17:38:04 volumio volumio[8687]: - /data/plugins/user_interface/now_playing/dist/index.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/app/pluginmanager.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/app/index.js Oct 18 17:38:04 volumio volumio[8687]: - /volumio/index.js Oct 18 17:38:04 volumio volumio[8687]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Oct 18 17:38:04 volumio volumio[8687]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Oct 18 17:38:04 volumio volumio[8687]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 18 17:38:04 volumio volumio[8687]: at require (internal/modules/cjs/helpers.js:88:18) Oct 18 17:38:04 volumio volumio[8687]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Oct 18 17:38:04 volumio volumio[8687]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Oct 18 17:38:04 volumio volumio[8687]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Oct 18 17:38:04 volumio volumio[8687]: at Module.load (internal/modules/cjs/loader.js:928:32) Oct 18 17:38:04 volumio volumio[8687]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Oct 18 17:38:04 volumio volumio[8687]: at Module.require (internal/modules/cjs/loader.js:952:19) Oct 18 17:38:04 volumio volumio[8687]: at require (internal/modules/cjs/helpers.js:88:18) Oct 18 17:38:04 volumio volumio[8687]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Oct 18 17:38:04 volumio volumio[8687]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Oct 18 17:38:04 volumio volumio[8687]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 18 17:38:04 volumio volumio[8687]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 18 17:38:04 volumio volumio[8687]: error: !!!! WARNING !!!! Oct 18 17:38:04 volumio volumio[8687]: info: Done. Oct 18 17:38:05 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:38:05 volumio volumio[8687]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 17:38:06 volumio kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1) Oct 18 17:38:06 volumio volumio[8687]: info: camilladsp spawned new process with pid 9098, instance 1, run: true Oct 18 17:38:07 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 18 17:38:07 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 18 17:38:07 volumio volumio[8687]: info: Discovery: Getting this device information Oct 18 17:38:07 volumio volumio[8687]: info: CoreCommandRouter::volumioGetState Oct 18 17:38:07 volumio volumio[8687]: info: CorePlayQueue::getTrack 0 Oct 18 17:38:07 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 18 17:38:10 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 18 17:38:10 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 18 17:38:11 volumio volumio[8687]: error: error Oct 18 17:38:11 volumio volumio[8687]: error: error Oct 18 17:38:16 volumio volumio[8687]: info: Starting Uninstall of plugin user_interface - now_playing Oct 18 17:38:16 volumio volumio[8687]: info: Uninstalling plugin now_playing Oct 18 17:38:20 volumio volumio[8687]: info: Starting Uninstall of plugin user_interface - now_playing Oct 18 17:38:20 volumio volumio[8687]: info: Uninstalling plugin now_playing Oct 18 17:38:25 volumio volumio[8687]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 18 17:38:27 volumio volumio[8687]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/download/now_playing/0.7.3/volumio/buster/armhf Oct 18 17:38:27 volumio volumio[8687]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 18 17:38:27 volumio volumio[8687]: TypeError: Cannot read property 'broadcastMessage' of null Oct 18 17:38:27 volumio volumio[8687]: at /volumio/app/index.js:1515:32 Oct 18 17:38:27 volumio volumio[8687]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Oct 18 17:38:27 volumio volumio[8687]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Oct 18 17:38:27 volumio volumio[8687]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1513:13) Oct 18 17:38:27 volumio volumio[8687]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Oct 18 17:38:27 volumio volumio[8687]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Oct 18 17:38:27 volumio volumio[8687]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1434:22) Oct 18 17:38:27 volumio volumio[8687]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1195:47) Oct 18 17:38:27 volumio volumio[8687]: at Socket.emit (events.js:315:20) Oct 18 17:38:27 volumio volumio[8687]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 18 17:38:27 volumio volumio[8687]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 18 17:38:27 volumio volumio[8687]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 18 17:38:28 volumio sudo[9172]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-18 17:37 Oct 18 17:38:28 volumio sudo[9172]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"