-- Logs begin at Thu 2022-12-22 15:07:36 UTC, end at Thu 2022-12-22 15:31:15 UTC. -- Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "wizard"... Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "volumio_command_line_client"... Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "upnp"... Dec 22 15:30:00 volumio volumio[9379]: info: [1671723000070] Starting Upmpd Daemon Dec 22 15:30:00 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "my_music"... Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "mpd"... Dec 22 15:30:00 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:00 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32042. Dec 22 15:30:00 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:00 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:00 volumio volumio[9412]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:00 volumio volumio[9412]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:00 volumio volumio[9412]: Malformed config key: missing field `Authentication` Dec 22 15:30:00 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:00 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:00 volumio volumio[9379]: info: Creating MPD Configuration file Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "upnp_browser"... Dec 22 15:30:00 volumio sudo[9409]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 22 15:30:00 volumio sudo[9409]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:00 volumio sudo[9415]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:00 volumio sudo[9415]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:00 volumio sudo[9407]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:30:00 volumio sudo[9417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:00 volumio sudo[9405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:30:00 volumio sudo[9415]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:00 volumio sudo[9417]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:00 volumio sudo[9407]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:00 volumio sudo[9405]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:00 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:00 volumio sudo[9405]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:00 volumio sudo[9407]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:00 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:00 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:00 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:00 volumio volumio[9379]: info: Loading plugin "networkfs"... Dec 22 15:30:00 volumio volumio-remote-updater[494]: [2022-12-22 15:30:00] [connect] Successful connection Dec 22 15:30:01 volumio volumio[9379]: info: Starting Udev Watcher for removable devices Dec 22 15:30:01 volumio sudo[9428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nico,password=Fraise33,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/music /mnt/NAS/nestorNas Dec 22 15:30:01 volumio sudo[9428]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:01 volumio sudo[9428]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:01 volumio kernel: CIFS: Attempting to mount //192.168.1.16/music Dec 22 15:30:01 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 22 15:30:01 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 22 15:30:01 volumio volumio[9379]: info: Ignoring mount for partition: boot Dec 22 15:30:01 volumio volumio[9379]: info: Ignoring mount for partition: volumio Dec 22 15:30:01 volumio volumio[9379]: info: Ignoring mount for partition: volumio_data Dec 22 15:30:01 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "alarm-clock"... Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "airplay_emulation"... Dec 22 15:30:01 volumio volumio[9379]: info: Starting Shairport Sync Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "last_100"... Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "webradio"... Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "i2s_dacs"... Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "volumiodiscovery"... Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** For more information see Dec 22 15:30:01 volumio node[9379]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:01 volumio volumio[9379]: *** WARNING *** For more information see Dec 22 15:30:01 volumio node[9379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:01 volumio node[9379]: *** WARNING *** For more information see Dec 22 15:30:01 volumio node[9379]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:01 volumio node[9379]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:01 volumio node[9379]: *** WARNING *** For more information see Dec 22 15:30:01 volumio volumio[9379]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 22 15:30:01 volumio volumio[9379]: info: Discovery: Started advertising with name: Volumio Dec 22 15:30:01 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:01 volumio volumio[9379]: info: Loading plugin "spop"... Dec 22 15:30:02 volumio mpd[9425]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:02 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:02 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32043. Dec 22 15:30:02 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:02 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:02 volumio volumio[9434]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:02 volumio mpd[9425]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:02 volumio mpd[9425]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:02 volumio volumio[9434]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:02 volumio volumio[9434]: Malformed config key: missing field `Authentication` Dec 22 15:30:02 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:02 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:02 volumio volumio[9379]: info: Loading plugin "youtube2"... Dec 22 15:30:02 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:03 volumio sudo[9417]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:03 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:03 volumio sudo[9409]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:03 volumio ntpd[656]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Dec 22 15:30:04 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:04 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32044. Dec 22 15:30:04 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:04 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:04 volumio volumio[9439]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:04 volumio volumio[9439]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:04 volumio volumio[9439]: Malformed config key: missing field `Authentication` Dec 22 15:30:04 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:04 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:06 volumio ntpd[656]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Dec 22 15:30:06 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:06 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32045. Dec 22 15:30:06 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:06 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:06 volumio volumio[9441]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:06 volumio volumio[9441]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:06 volumio volumio[9441]: Malformed config key: missing field `Authentication` Dec 22 15:30:06 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:06 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "outputs"... Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "albumart"... Dec 22 15:30:07 volumio volumio[9379]: info: Plugin example_plugin is not enabled Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "inputs"... Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "updater_comm"... Dec 22 15:30:07 volumio volumio[9379]: info: Plugin mpdemulation is not enabled Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "rest_api"... Dec 22 15:30:07 volumio volumio[9379]: info: Loading plugin "websocket"... Dec 22 15:30:07 volumio volumio[9379]: info: Loading i18n strings for locale fr Dec 22 15:30:07 volumio volumio[9379]: Updating browse sources language Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::initPlayerControls Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: Express server listening on port 3000 Dec 22 15:30:07 volumio volumio[9379]: [Metrics] WebUI: 10s 63.63ms Dec 22 15:30:07 volumio volumio[9379]: info: CoreStateMachine::resetVolumioState Dec 22 15:30:07 volumio volumio[9379]: info: CoreStateMachine::getcurrentVolume Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:07 volumio volumio[9379]: info: Cannot mount NAS nestorNas at system boot, trial number 1 ,retrying in 5 seconds Dec 22 15:30:07 volumio volumio[9379]: Forking 3 albumart workers Dec 22 15:30:07 volumio volumio[9379]: info: MPD Permissions set Dec 22 15:30:07 volumio volumio[9379]: info: CoreStateMachine::pushState Dec 22 15:30:07 volumio volumio[9379]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:07 volumio volumio[9379]: info: CoreStateMachine::updateTrackBlock Dec 22 15:30:07 volumio volumio[9379]: info: CorePlayQueue::getTrackBlock Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:07 volumio volumio[9379]: info: MPD running with PID9425 Dec 22 15:30:07 volumio volumio[9379]: ,establishing connection Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:07 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: Reloading queue from file Dec 22 15:30:08 volumio volumio[9379]: error: updateQueue error: null Dec 22 15:30:08 volumio volumio[9379]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 22 15:30:08 volumio volumio[9379]: info: CoreStateMachine::setRepeat null single undefined Dec 22 15:30:08 volumio volumio[9379]: info: CoreStateMachine::pushState Dec 22 15:30:08 volumio volumio[9379]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:08 volumio volumio[9379]: info: CoreStateMachine::setRandom null Dec 22 15:30:08 volumio volumio[9379]: info: CoreStateMachine::pushState Dec 22 15:30:08 volumio volumio[9379]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:08 volumio volumio[9379]: info: Setting Device type: Raspberry PI Dec 22 15:30:08 volumio volumio[9379]: info: Completed loading Core Plugins Dec 22 15:30:08 volumio volumio[9379]: info: Preparing to generate the ALSA configuration file Dec 22 15:30:08 volumio volumio[9379]: info: CoreStateMachine::pushState Dec 22 15:30:08 volumio volumio[9379]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:08 volumio volumio[9379]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 15:30:08 volumio volumio[9379]: info: Reading ALSA contributions from plugins. Dec 22 15:30:08 volumio volumio[9379]: info: Asound.conf file unchanged, so no further update is needed Dec 22 15:30:08 volumio volumio[9379]: info: Output device has changed, restarting MPD Dec 22 15:30:08 volumio sudo[9498]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:08 volumio sudo[9498]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:08 volumio sudo[9498]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:08 volumio volumio[9379]: info: Output device has changed, restarting Shairport Sync Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:08 volumio sudo[9500]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:08 volumio sudo[9500]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:08 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:08 volumio volumio[9379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:08 volumio volumio[9379]: info: ___________ START PLUGINS ___________ Dec 22 15:30:08 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:08 volumio volumio[9379]: info: [1671723008412] CoreMusicLibrary::Adding element Media Servers Dec 22 15:30:08 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:08 volumio volumio[9379]: Cannot find translation for sourceMedia Servers Dec 22 15:30:08 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:08 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:08 volumio volumio[9379]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:08 volumio volumio[9379]: info: [1671723008602] CoreMusicLibrary::Adding element Last_100 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:08 volumio volumio[9379]: Cannot find translation for sourceMedia Servers Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:08 volumio volumio[9379]: info: [1671723008608] CoreMusicLibrary::Adding element Webradio Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:08 volumio volumio[9379]: Cannot find translation for sourceMedia Servers Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 15:30:08 volumio volumio[9379]: info: Checking for old spotify connect plugin installed Dec 22 15:30:08 volumio volumio[9379]: info: [youtube2-auth] Starting auth flow... Dec 22 15:30:08 volumio volumio[9379]: Starting albumart workers Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:08 volumio volumio[9379]: info: [1671723008934] CoreMusicLibrary::Adding element YouTube2 Dec 22 15:30:08 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:08 volumio volumio[9379]: Cannot find translation for sourceMedia Servers Dec 22 15:30:08 volumio volumio[9379]: Cannot find translation for sourceYouTube2 Dec 22 15:30:08 volumio volumio[9379]: info: Volumio Calling Home Dec 22 15:30:09 volumio volumio[9379]: Starting albumart workers Dec 22 15:30:09 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:09 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32046. Dec 22 15:30:09 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:09 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:09 volumio volumio[9516]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:09 volumio volumio[9516]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:09 volumio volumio[9516]: Malformed config key: missing field `Authentication` Dec 22 15:30:09 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:09 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:09 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:09 volumio volumio[9379]: [SpotifyConnect] Creating VLS config file Dec 22 15:30:09 volumio volumio[9379]: Starting albumart workers Dec 22 15:30:09 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:09 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:09 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:09 volumio volumio[9379]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:09 volumio volumio[9379]: [SpotifyConnect] Starting metadata listener Dec 22 15:30:09 volumio volumio[9379]: Unhandled rejection Error: No sockets available, cannot start. Dec 22 15:30:09 volumio volumio[9379]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 22 15:30:09 volumio volumio[9379]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 22 15:30:09 volumio volumio[9379]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 22 15:30:09 volumio volumio[9379]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 22 15:30:09 volumio volumio[9379]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 22 15:30:09 volumio volumio[9379]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 22 15:30:09 volumio volumio[9379]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 22 15:30:09 volumio volumio[9379]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 22 15:30:09 volumio volumio[9379]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Dec 22 15:30:09 volumio volumio[9379]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 22 15:30:09 volumio volumio[9379]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 22 15:30:09 volumio volumio[9379]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 22 15:30:09 volumio volumio[9379]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 22 15:30:09 volumio volumio[9379]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 22 15:30:09 volumio volumio[9379]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 22 15:30:09 volumio volumio[9379]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 22 15:30:09 volumio volumio[9379]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:09 volumio volumio[9379]: ReferenceError: deferred is not defined Dec 22 15:30:09 volumio volumio[9379]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Dec 22 15:30:09 volumio volumio[9379]: at ClientRequest.emit (events.js:315:20) Dec 22 15:30:09 volumio volumio[9379]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Dec 22 15:30:09 volumio volumio[9379]: at TLSSocket.emit (events.js:315:20) Dec 22 15:30:09 volumio volumio[9379]: at emitErrorNT (internal/streams/destroy.js:106:8) Dec 22 15:30:09 volumio volumio[9379]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Dec 22 15:30:09 volumio volumio[9379]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 22 15:30:09 volumio volumio[9379]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:10 volumio mpd[9513]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:10 volumio sudo[9520]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 22 15:30:10 volumio sudo[9554]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-12-22 15:29 Dec 22 15:30:10 volumio sudo[9520]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:10 volumio sudo[9554]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:10 volumio sudo[9554]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:10 volumio mpd[9513]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:10 volumio mpd[9513]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:10 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:10 volumio sudo[9500]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:10 volumio sudo[9520]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 22 15:30:10 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:10 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:11 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Dec 22 15:30:11 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4505. Dec 22 15:30:11 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:11 volumio systemd[1]: Stopped Volumio Backend Module. Dec 22 15:30:11 volumio systemd[1]: Started Volumio Backend Module. Dec 22 15:30:11 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:11 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:11 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32047. Dec 22 15:30:11 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:11 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:11 volumio volumio[9582]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:11 volumio volumio[9582]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:11 volumio volumio[9582]: Malformed config key: missing field `Authentication` Dec 22 15:30:11 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:11 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:13 volumio volumio[9571]: info: ------------------------------------------- Dec 22 15:30:13 volumio volumio[9571]: info: ----- Volumio3 ---- Dec 22 15:30:13 volumio volumio[9571]: info: ------------------------------------------- Dec 22 15:30:13 volumio volumio[9571]: info: ----- System startup ---- Dec 22 15:30:13 volumio volumio[9571]: info: ------------------------------------------- Dec 22 15:30:13 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:13 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32048. Dec 22 15:30:13 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:13 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:13 volumio volumio[9593]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:13 volumio volumio[9593]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:13 volumio volumio[9593]: Malformed config key: missing field `Authentication` Dec 22 15:30:13 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:13 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:13 volumio volumio-remote-updater[494]: [2022-12-22 15:30:13] [connect] Successful connection Dec 22 15:30:13 volumio volumio[9571]: info: MYVOLUMIO Environment detected Dec 22 15:30:13 volumio volumio[9571]: info: Plugin folders cleanup Dec 22 15:30:13 volumio volumio[9571]: info: Scanning into folder /volumio/app/plugins/ Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category audio_interface Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category miscellanea Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category music_service Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category plugins.json Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category system_controller Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category user_interface Dec 22 15:30:13 volumio volumio[9571]: info: Scanning into folder /data/plugins/ Dec 22 15:30:13 volumio volumio[9571]: info: Scanning category music_service Dec 22 15:30:13 volumio volumio[9571]: info: Plugin folders cleanup completed Dec 22 15:30:13 volumio volumio[9571]: info: ------------------------------------------- Dec 22 15:30:13 volumio volumio[9571]: info: ----- Core plugins startup ---- Dec 22 15:30:13 volumio volumio[9571]: info: ------------------------------------------- Dec 22 15:30:13 volumio volumio[9571]: info: Loading plugins from folder /volumio/app/plugins/ Dec 22 15:30:13 volumio volumio[9571]: info: Adding plugin upnp to MyMusic Plugins Dec 22 15:30:13 volumio volumio[9571]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 22 15:30:13 volumio volumio[9571]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 22 15:30:13 volumio volumio[9571]: info: Loading plugins from folder /data/plugins/ Dec 22 15:30:13 volumio volumio[9571]: info: Loading plugin "system"... Dec 22 15:30:13 volumio volumio[9571]: info: Loading plugin "appearance"... Dec 22 15:30:14 volumio volumio[9571]: info: Loading plugin "network"... Dec 22 15:30:14 volumio volumio[9571]: info: Refreshing Cached IP Addresses Dec 22 15:30:14 volumio volumio[9571]: info: Loading plugin "services"... Dec 22 15:30:14 volumio volumio[9571]: info: Loading plugin "alsa_controller"... Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "wizard"... Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "volumio_command_line_client"... Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "upnp"... Dec 22 15:30:15 volumio volumio[9571]: info: [1671723015080] Starting Upmpd Daemon Dec 22 15:30:15 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "my_music"... Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "mpd"... Dec 22 15:30:15 volumio volumio[9571]: info: Creating MPD Configuration file Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "upnp_browser"... Dec 22 15:30:15 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:15 volumio sudo[9600]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:30:15 volumio sudo[9600]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:15 volumio sudo[9602]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 22 15:30:15 volumio sudo[9602]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:15 volumio sudo[9598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:30:15 volumio sudo[9598]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:15 volumio sudo[9606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:15 volumio sudo[9606]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:15 volumio sudo[9606]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:15 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:15 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32049. Dec 22 15:30:15 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:15 volumio sudo[9608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:15 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:15 volumio sudo[9608]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:15 volumio sudo[9598]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:15 volumio volumio[9613]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:15 volumio volumio[9613]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:15 volumio volumio[9613]: Malformed config key: missing field `Authentication` Dec 22 15:30:15 volumio sudo[9600]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:15 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:15 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:15 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:15 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:15 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:15 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:15 volumio volumio[9571]: info: Loading plugin "networkfs"... Dec 22 15:30:16 volumio volumio[9571]: info: Starting Udev Watcher for removable devices Dec 22 15:30:16 volumio sudo[9621]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nico,password=Fraise33,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/music /mnt/NAS/nestorNas Dec 22 15:30:16 volumio sudo[9621]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:16 volumio sudo[9621]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:16 volumio kernel: CIFS: Attempting to mount //192.168.1.16/music Dec 22 15:30:16 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 22 15:30:16 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 22 15:30:16 volumio sudo[9602]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:16 volumio volumio[9571]: info: Ignoring mount for partition: boot Dec 22 15:30:16 volumio volumio[9571]: info: Ignoring mount for partition: volumio Dec 22 15:30:16 volumio volumio[9571]: info: Ignoring mount for partition: volumio_data Dec 22 15:30:16 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "alarm-clock"... Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "airplay_emulation"... Dec 22 15:30:16 volumio volumio[9571]: info: Starting Shairport Sync Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "last_100"... Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "webradio"... Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "i2s_dacs"... Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "volumiodiscovery"... Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** For more information see Dec 22 15:30:16 volumio node[9571]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:16 volumio volumio[9571]: *** WARNING *** For more information see Dec 22 15:30:16 volumio node[9571]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:16 volumio node[9571]: *** WARNING *** For more information see Dec 22 15:30:16 volumio node[9571]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:16 volumio node[9571]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:16 volumio node[9571]: *** WARNING *** For more information see Dec 22 15:30:16 volumio volumio[9571]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 22 15:30:16 volumio volumio[9571]: info: Discovery: Started advertising with name: Volumio Dec 22 15:30:16 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:16 volumio volumio[9571]: info: Loading plugin "spop"... Dec 22 15:30:17 volumio mpd[9618]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:17 volumio mpd[9618]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:17 volumio mpd[9618]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:17 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:17 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32050. Dec 22 15:30:17 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:17 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:17 volumio volumio[9571]: info: Loading plugin "youtube2"... Dec 22 15:30:17 volumio volumio[9627]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:17 volumio volumio[9627]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:17 volumio volumio[9627]: Malformed config key: missing field `Authentication` Dec 22 15:30:17 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:17 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:18 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:18 volumio sudo[9608]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:20 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:20 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32051. Dec 22 15:30:20 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:20 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:20 volumio volumio[9631]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:20 volumio volumio[9631]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:20 volumio volumio[9631]: Malformed config key: missing field `Authentication` Dec 22 15:30:20 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:20 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:21 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "outputs"... Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "albumart"... Dec 22 15:30:22 volumio volumio[9571]: info: Plugin example_plugin is not enabled Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "inputs"... Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "updater_comm"... Dec 22 15:30:22 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:22 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32052. Dec 22 15:30:22 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:22 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:22 volumio volumio[9571]: info: Plugin mpdemulation is not enabled Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "rest_api"... Dec 22 15:30:22 volumio volumio[9640]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:22 volumio volumio[9640]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:22 volumio volumio[9640]: Malformed config key: missing field `Authentication` Dec 22 15:30:22 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:22 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:22 volumio volumio[9571]: info: Loading plugin "websocket"... Dec 22 15:30:22 volumio volumio[9571]: info: Loading i18n strings for locale fr Dec 22 15:30:22 volumio volumio[9571]: Updating browse sources language Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::initPlayerControls Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: Express server listening on port 3000 Dec 22 15:30:22 volumio volumio[9571]: [Metrics] WebUI: 10s 54.60ms Dec 22 15:30:22 volumio volumio[9571]: info: CoreStateMachine::resetVolumioState Dec 22 15:30:22 volumio volumio[9571]: info: CoreStateMachine::getcurrentVolume Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:22 volumio volumio[9571]: info: Cannot mount NAS nestorNas at system boot, trial number 1 ,retrying in 5 seconds Dec 22 15:30:22 volumio volumio[9571]: Forking 3 albumart workers Dec 22 15:30:22 volumio volumio[9571]: info: MPD Permissions set Dec 22 15:30:22 volumio volumio[9571]: info: CoreStateMachine::pushState Dec 22 15:30:22 volumio volumio[9571]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:22 volumio volumio[9571]: info: CoreStateMachine::updateTrackBlock Dec 22 15:30:22 volumio volumio[9571]: info: CorePlayQueue::getTrackBlock Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:22 volumio volumio[9571]: info: MPD running with PID9618 Dec 22 15:30:22 volumio volumio[9571]: ,establishing connection Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:22 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: Reloading queue from file Dec 22 15:30:23 volumio volumio[9571]: error: updateQueue error: null Dec 22 15:30:23 volumio volumio[9571]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 22 15:30:23 volumio volumio[9571]: info: CoreStateMachine::setRepeat null single undefined Dec 22 15:30:23 volumio volumio[9571]: info: CoreStateMachine::pushState Dec 22 15:30:23 volumio volumio[9571]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:23 volumio volumio[9571]: info: CoreStateMachine::setRandom null Dec 22 15:30:23 volumio volumio[9571]: info: CoreStateMachine::pushState Dec 22 15:30:23 volumio volumio[9571]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:23 volumio volumio[9571]: info: Setting Device type: Raspberry PI Dec 22 15:30:23 volumio volumio[9571]: info: Completed loading Core Plugins Dec 22 15:30:23 volumio volumio[9571]: info: Preparing to generate the ALSA configuration file Dec 22 15:30:23 volumio volumio[9571]: info: CoreStateMachine::pushState Dec 22 15:30:23 volumio volumio[9571]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:23 volumio volumio[9571]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 15:30:23 volumio volumio[9571]: info: Reading ALSA contributions from plugins. Dec 22 15:30:23 volumio volumio[9571]: info: Asound.conf file unchanged, so no further update is needed Dec 22 15:30:23 volumio volumio[9571]: info: Output device has changed, restarting MPD Dec 22 15:30:23 volumio sudo[9689]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:23 volumio volumio[9571]: info: Output device has changed, restarting Shairport Sync Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:23 volumio sudo[9689]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:23 volumio sudo[9689]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:23 volumio sudo[9692]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:23 volumio sudo[9692]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:23 volumio volumio[9571]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:23 volumio volumio[9571]: info: ___________ START PLUGINS ___________ Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:23 volumio volumio[9571]: info: [1671723023319] CoreMusicLibrary::Adding element Media Servers Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:23 volumio volumio[9571]: Cannot find translation for sourceMedia Servers Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:23 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:23 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:23 volumio volumio[9571]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:23 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:23 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:23 volumio volumio[9571]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:23 volumio volumio[9571]: info: [1671723023545] CoreMusicLibrary::Adding element Last_100 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:23 volumio volumio[9571]: Cannot find translation for sourceMedia Servers Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:23 volumio volumio[9571]: info: [1671723023550] CoreMusicLibrary::Adding element Webradio Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:23 volumio volumio[9571]: Cannot find translation for sourceMedia Servers Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 15:30:23 volumio volumio[9571]: info: Checking for old spotify connect plugin installed Dec 22 15:30:23 volumio volumio[9571]: info: [youtube2-auth] Starting auth flow... Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:23 volumio volumio[9571]: info: [1671723023707] CoreMusicLibrary::Adding element YouTube2 Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:23 volumio volumio[9571]: Cannot find translation for sourceMedia Servers Dec 22 15:30:23 volumio volumio[9571]: Cannot find translation for sourceYouTube2 Dec 22 15:30:23 volumio volumio[9571]: info: Volumio Calling Home Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:23 volumio volumio[9571]: [SpotifyConnect] Creating VLS config file Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:23 volumio volumio[9571]: [SpotifyConnect] Starting metadata listener Dec 22 15:30:24 volumio volumio[9571]: Starting albumart workers Dec 22 15:30:24 volumio volumio[9571]: Unhandled rejection Error: No sockets available, cannot start. Dec 22 15:30:24 volumio volumio[9571]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 22 15:30:24 volumio volumio[9571]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 22 15:30:24 volumio volumio[9571]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 22 15:30:24 volumio volumio[9571]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 22 15:30:24 volumio volumio[9571]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 22 15:30:24 volumio volumio[9571]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 22 15:30:24 volumio volumio[9571]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 22 15:30:24 volumio volumio[9571]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 22 15:30:24 volumio volumio[9571]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Dec 22 15:30:24 volumio volumio[9571]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 22 15:30:24 volumio volumio[9571]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 22 15:30:24 volumio volumio[9571]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 22 15:30:24 volumio volumio[9571]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 22 15:30:24 volumio volumio[9571]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 22 15:30:24 volumio volumio[9571]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 22 15:30:24 volumio volumio[9571]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 22 15:30:24 volumio volumio[9571]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:24 volumio volumio[9571]: ReferenceError: deferred is not defined Dec 22 15:30:24 volumio volumio[9571]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Dec 22 15:30:24 volumio volumio[9571]: at ClientRequest.emit (events.js:315:20) Dec 22 15:30:24 volumio volumio[9571]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Dec 22 15:30:24 volumio volumio[9571]: at TLSSocket.emit (events.js:315:20) Dec 22 15:30:24 volumio volumio[9571]: at emitErrorNT (internal/streams/destroy.js:106:8) Dec 22 15:30:24 volumio volumio[9571]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Dec 22 15:30:24 volumio volumio[9571]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 22 15:30:24 volumio volumio[9571]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:24 volumio sudo[9710]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 22 15:30:24 volumio sudo[9710]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:24 volumio volumio[9571]: Starting albumart workers Dec 22 15:30:24 volumio volumio[9571]: Starting albumart workers Dec 22 15:30:24 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:24 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32053. Dec 22 15:30:24 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:24 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:24 volumio sudo[9710]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:24 volumio volumio[9720]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:24 volumio volumio[9720]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:24 volumio volumio[9720]: Malformed config key: missing field `Authentication` Dec 22 15:30:24 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:24 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:25 volumio mpd[9706]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:25 volumio sudo[9731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-12-22 15:29 Dec 22 15:30:25 volumio sudo[9731]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:25 volumio mpd[9706]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:25 volumio mpd[9706]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:25 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:25 volumio sudo[9692]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:25 volumio sudo[9731]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 22 15:30:25 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:26 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:26 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Dec 22 15:30:26 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4506. Dec 22 15:30:26 volumio systemd[1]: Stopped Volumio Backend Module. Dec 22 15:30:26 volumio systemd[1]: Started Volumio Backend Module. Dec 22 15:30:26 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:26 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:26 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:26 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32054. Dec 22 15:30:26 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:26 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:26 volumio volumio[9775]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:26 volumio volumio[9775]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:26 volumio volumio[9775]: Malformed config key: missing field `Authentication` Dec 22 15:30:26 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:26 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:28 volumio volumio[9762]: info: ------------------------------------------- Dec 22 15:30:28 volumio volumio[9762]: info: ----- Volumio3 ---- Dec 22 15:30:28 volumio volumio[9762]: info: ------------------------------------------- Dec 22 15:30:28 volumio volumio[9762]: info: ----- System startup ---- Dec 22 15:30:28 volumio volumio[9762]: info: ------------------------------------------- Dec 22 15:30:28 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:28 volumio volumio-remote-updater[494]: [2022-12-22 15:30:28] [connect] Successful connection Dec 22 15:30:28 volumio volumio[9762]: info: MYVOLUMIO Environment detected Dec 22 15:30:28 volumio volumio[9762]: info: Plugin folders cleanup Dec 22 15:30:28 volumio volumio[9762]: info: Scanning into folder /volumio/app/plugins/ Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category audio_interface Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category miscellanea Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category music_service Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category plugins.json Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category system_controller Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category user_interface Dec 22 15:30:28 volumio volumio[9762]: info: Scanning into folder /data/plugins/ Dec 22 15:30:28 volumio volumio[9762]: info: Scanning category music_service Dec 22 15:30:28 volumio volumio[9762]: info: Plugin folders cleanup completed Dec 22 15:30:28 volumio volumio[9762]: info: ------------------------------------------- Dec 22 15:30:28 volumio volumio[9762]: info: ----- Core plugins startup ---- Dec 22 15:30:28 volumio volumio[9762]: info: ------------------------------------------- Dec 22 15:30:28 volumio volumio[9762]: info: Loading plugins from folder /volumio/app/plugins/ Dec 22 15:30:28 volumio volumio[9762]: info: Adding plugin upnp to MyMusic Plugins Dec 22 15:30:28 volumio volumio[9762]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 22 15:30:28 volumio volumio[9762]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 22 15:30:28 volumio volumio[9762]: info: Loading plugins from folder /data/plugins/ Dec 22 15:30:28 volumio volumio[9762]: info: Loading plugin "system"... Dec 22 15:30:28 volumio volumio[9762]: info: Loading plugin "appearance"... Dec 22 15:30:29 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:29 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32055. Dec 22 15:30:29 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:29 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:29 volumio volumio[9787]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:29 volumio volumio[9787]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:29 volumio volumio[9787]: Malformed config key: missing field `Authentication` Dec 22 15:30:29 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:29 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:29 volumio volumio[9762]: info: Loading plugin "network"... Dec 22 15:30:29 volumio volumio[9762]: info: Refreshing Cached IP Addresses Dec 22 15:30:29 volumio volumio[9762]: info: Loading plugin "services"... Dec 22 15:30:29 volumio volumio[9762]: info: Loading plugin "alsa_controller"... Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "wizard"... Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "volumio_command_line_client"... Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "upnp"... Dec 22 15:30:30 volumio volumio[9762]: info: [1671723030047] Starting Upmpd Daemon Dec 22 15:30:30 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "my_music"... Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "mpd"... Dec 22 15:30:30 volumio volumio[9762]: info: Creating MPD Configuration file Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "upnp_browser"... Dec 22 15:30:30 volumio sudo[9798]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:30 volumio sudo[9792]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:30:30 volumio sudo[9792]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:30 volumio sudo[9790]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:30:30 volumio sudo[9790]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:30 volumio sudo[9792]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:30 volumio sudo[9794]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 22 15:30:30 volumio sudo[9800]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:30 volumio sudo[9800]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:30 volumio sudo[9798]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:30 volumio sudo[9794]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:30 volumio sudo[9790]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:30 volumio sudo[9798]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:30 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:30 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:30 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:30 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:30 volumio volumio[9762]: info: Loading plugin "networkfs"... Dec 22 15:30:31 volumio volumio[9762]: info: Starting Udev Watcher for removable devices Dec 22 15:30:31 volumio sudo[9811]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nico,password=Fraise33,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/music /mnt/NAS/nestorNas Dec 22 15:30:31 volumio sudo[9811]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:31 volumio sudo[9811]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:31 volumio kernel: CIFS: Attempting to mount //192.168.1.16/music Dec 22 15:30:31 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 22 15:30:31 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 22 15:30:31 volumio sudo[9794]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:31 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:31 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32056. Dec 22 15:30:31 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:31 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:31 volumio volumio[9762]: info: Ignoring mount for partition: boot Dec 22 15:30:31 volumio volumio[9762]: info: Ignoring mount for partition: volumio Dec 22 15:30:31 volumio volumio[9762]: info: Ignoring mount for partition: volumio_data Dec 22 15:30:31 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "alarm-clock"... Dec 22 15:30:31 volumio volumio[9815]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:31 volumio volumio[9815]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:31 volumio volumio[9815]: Malformed config key: missing field `Authentication` Dec 22 15:30:31 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:31 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "airplay_emulation"... Dec 22 15:30:31 volumio volumio[9762]: info: Starting Shairport Sync Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "last_100"... Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "webradio"... Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "i2s_dacs"... Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "volumiodiscovery"... Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** For more information see Dec 22 15:30:31 volumio node[9762]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:31 volumio volumio[9762]: *** WARNING *** For more information see Dec 22 15:30:31 volumio node[9762]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:31 volumio node[9762]: *** WARNING *** For more information see Dec 22 15:30:31 volumio node[9762]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:31 volumio node[9762]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:31 volumio node[9762]: *** WARNING *** For more information see Dec 22 15:30:31 volumio volumio[9762]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 22 15:30:31 volumio volumio[9762]: info: Discovery: Started advertising with name: Volumio Dec 22 15:30:31 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:31 volumio volumio[9762]: info: Loading plugin "spop"... Dec 22 15:30:32 volumio mpd[9808]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:32 volumio mpd[9808]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:32 volumio mpd[9808]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:32 volumio volumio[9762]: info: Loading plugin "youtube2"... Dec 22 15:30:33 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:33 volumio sudo[9800]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:33 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:33 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32057. Dec 22 15:30:33 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:33 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:33 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:33 volumio volumio[9821]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:33 volumio volumio[9821]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:33 volumio volumio[9821]: Malformed config key: missing field `Authentication` Dec 22 15:30:33 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:33 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:35 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:35 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32058. Dec 22 15:30:35 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:35 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:35 volumio volumio[9823]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:35 volumio volumio[9823]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:35 volumio volumio[9823]: Malformed config key: missing field `Authentication` Dec 22 15:30:35 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:35 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "outputs"... Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "albumart"... Dec 22 15:30:37 volumio volumio[9762]: info: Plugin example_plugin is not enabled Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "inputs"... Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "updater_comm"... Dec 22 15:30:37 volumio volumio[9762]: info: Plugin mpdemulation is not enabled Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "rest_api"... Dec 22 15:30:37 volumio volumio[9762]: info: Loading plugin "websocket"... Dec 22 15:30:37 volumio volumio[9762]: info: Loading i18n strings for locale fr Dec 22 15:30:37 volumio volumio[9762]: Updating browse sources language Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::initPlayerControls Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: Express server listening on port 3000 Dec 22 15:30:37 volumio volumio[9762]: [Metrics] WebUI: 10s 17.27ms Dec 22 15:30:37 volumio volumio[9762]: info: CoreStateMachine::resetVolumioState Dec 22 15:30:37 volumio volumio[9762]: info: CoreStateMachine::getcurrentVolume Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:37 volumio volumio[9762]: info: Cannot mount NAS nestorNas at system boot, trial number 1 ,retrying in 5 seconds Dec 22 15:30:37 volumio volumio[9762]: info: MPD Permissions set Dec 22 15:30:37 volumio volumio[9762]: Forking 3 albumart workers Dec 22 15:30:37 volumio volumio[9762]: info: CoreStateMachine::pushState Dec 22 15:30:37 volumio volumio[9762]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:37 volumio volumio[9762]: info: CoreStateMachine::updateTrackBlock Dec 22 15:30:37 volumio volumio[9762]: info: CorePlayQueue::getTrackBlock Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:37 volumio volumio[9762]: info: MPD running with PID9808 Dec 22 15:30:37 volumio volumio[9762]: ,establishing connection Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:37 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: Reloading queue from file Dec 22 15:30:38 volumio volumio[9762]: error: updateQueue error: null Dec 22 15:30:38 volumio volumio[9762]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 22 15:30:38 volumio volumio[9762]: info: CoreStateMachine::pushState Dec 22 15:30:38 volumio volumio[9762]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:38 volumio volumio[9762]: info: CoreStateMachine::setRepeat null single undefined Dec 22 15:30:38 volumio volumio[9762]: info: CoreStateMachine::pushState Dec 22 15:30:38 volumio volumio[9762]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:38 volumio volumio[9762]: info: CoreStateMachine::setRandom null Dec 22 15:30:38 volumio volumio[9762]: info: CoreStateMachine::pushState Dec 22 15:30:38 volumio volumio[9762]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:38 volumio volumio[9762]: info: Setting Device type: Raspberry PI Dec 22 15:30:38 volumio volumio[9762]: info: Completed loading Core Plugins Dec 22 15:30:38 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:38 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32059. Dec 22 15:30:38 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:38 volumio volumio[9762]: info: Preparing to generate the ALSA configuration file Dec 22 15:30:38 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:38 volumio volumio[9878]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:38 volumio volumio[9878]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:38 volumio volumio[9878]: Malformed config key: missing field `Authentication` Dec 22 15:30:38 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:38 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:38 volumio volumio[9762]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 15:30:38 volumio volumio[9762]: info: Reading ALSA contributions from plugins. Dec 22 15:30:38 volumio volumio[9762]: info: Asound.conf file unchanged, so no further update is needed Dec 22 15:30:38 volumio volumio[9762]: info: Output device has changed, restarting MPD Dec 22 15:30:38 volumio volumio[9762]: info: Output device has changed, restarting Shairport Sync Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:38 volumio sudo[9881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:38 volumio sudo[9881]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:38 volumio sudo[9884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:38 volumio sudo[9881]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:38 volumio sudo[9884]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:38 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:38 volumio volumio[9762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:38 volumio volumio[9762]: info: ___________ START PLUGINS ___________ Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:38 volumio volumio[9762]: info: [1671723038420] CoreMusicLibrary::Adding element Media Servers Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:38 volumio volumio[9762]: Cannot find translation for sourceMedia Servers Dec 22 15:30:38 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:38 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:38 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:38 volumio volumio[9762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:38 volumio volumio[9762]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:38 volumio volumio[9762]: info: [1671723038643] CoreMusicLibrary::Adding element Last_100 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:38 volumio volumio[9762]: Cannot find translation for sourceMedia Servers Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:38 volumio volumio[9762]: info: [1671723038651] CoreMusicLibrary::Adding element Webradio Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:38 volumio volumio[9762]: Cannot find translation for sourceMedia Servers Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 15:30:38 volumio volumio[9762]: info: Checking for old spotify connect plugin installed Dec 22 15:30:38 volumio volumio[9762]: info: [youtube2-auth] Starting auth flow... Dec 22 15:30:38 volumio volumio[9762]: Starting albumart workers Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:38 volumio volumio[9762]: info: [1671723038818] CoreMusicLibrary::Adding element YouTube2 Dec 22 15:30:38 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:38 volumio volumio[9762]: Cannot find translation for sourceMedia Servers Dec 22 15:30:38 volumio volumio[9762]: Cannot find translation for sourceYouTube2 Dec 22 15:30:38 volumio volumio[9762]: info: Volumio Calling Home Dec 22 15:30:39 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:39 volumio volumio[9762]: [SpotifyConnect] Creating VLS config file Dec 22 15:30:39 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:39 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:39 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:39 volumio volumio[9762]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:39 volumio volumio[9762]: [SpotifyConnect] Starting metadata listener Dec 22 15:30:39 volumio volumio[9762]: Starting albumart workers Dec 22 15:30:39 volumio volumio[9762]: Unhandled rejection Error: No sockets available, cannot start. Dec 22 15:30:39 volumio volumio[9762]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 22 15:30:39 volumio volumio[9762]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 22 15:30:39 volumio volumio[9762]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 22 15:30:39 volumio volumio[9762]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 22 15:30:39 volumio volumio[9762]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 22 15:30:39 volumio volumio[9762]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 22 15:30:39 volumio volumio[9762]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 22 15:30:39 volumio volumio[9762]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 22 15:30:39 volumio volumio[9762]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Dec 22 15:30:39 volumio volumio[9762]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 22 15:30:39 volumio volumio[9762]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 22 15:30:39 volumio volumio[9762]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 22 15:30:39 volumio volumio[9762]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 22 15:30:39 volumio volumio[9762]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 22 15:30:39 volumio volumio[9762]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 22 15:30:39 volumio volumio[9762]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 22 15:30:39 volumio volumio[9762]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:39 volumio volumio[9762]: ReferenceError: deferred is not defined Dec 22 15:30:39 volumio volumio[9762]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Dec 22 15:30:39 volumio volumio[9762]: at ClientRequest.emit (events.js:315:20) Dec 22 15:30:39 volumio volumio[9762]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Dec 22 15:30:39 volumio volumio[9762]: at TLSSocket.emit (events.js:315:20) Dec 22 15:30:39 volumio volumio[9762]: at emitErrorNT (internal/streams/destroy.js:106:8) Dec 22 15:30:39 volumio volumio[9762]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Dec 22 15:30:39 volumio volumio[9762]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 22 15:30:39 volumio volumio[9762]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:39 volumio volumio[9762]: Starting albumart workers Dec 22 15:30:40 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:40 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32060. Dec 22 15:30:40 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:40 volumio ntpd[656]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Dec 22 15:30:40 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:40 volumio volumio[9937]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:40 volumio volumio[9937]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:40 volumio volumio[9937]: Malformed config key: missing field `Authentication` Dec 22 15:30:40 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:40 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:40 volumio mpd[9897]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:40 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:40 volumio sudo[9936]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-12-22 15:29 Dec 22 15:30:40 volumio sudo[9902]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 22 15:30:40 volumio sudo[9936]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:40 volumio sudo[9902]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:40 volumio mpd[9897]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:40 volumio mpd[9897]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:40 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:40 volumio sudo[9884]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:40 volumio sudo[9936]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:41 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:41 volumio sudo[9902]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:41 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 22 15:30:41 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:41 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:41 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Dec 22 15:30:41 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4507. Dec 22 15:30:41 volumio systemd[1]: Stopped Volumio Backend Module. Dec 22 15:30:41 volumio systemd[1]: Started Volumio Backend Module. Dec 22 15:30:41 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:41 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:42 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:42 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32061. Dec 22 15:30:42 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:42 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:42 volumio volumio[9967]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:42 volumio volumio[9967]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:42 volumio volumio[9967]: Malformed config key: missing field `Authentication` Dec 22 15:30:42 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:42 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:43 volumio volumio[9954]: info: ------------------------------------------- Dec 22 15:30:43 volumio volumio[9954]: info: ----- Volumio3 ---- Dec 22 15:30:43 volumio volumio[9954]: info: ------------------------------------------- Dec 22 15:30:43 volumio volumio[9954]: info: ----- System startup ---- Dec 22 15:30:43 volumio volumio[9954]: info: ------------------------------------------- Dec 22 15:30:43 volumio volumio-remote-updater[494]: [2022-12-22 15:30:43] [connect] Successful connection Dec 22 15:30:44 volumio volumio[9954]: info: MYVOLUMIO Environment detected Dec 22 15:30:44 volumio volumio[9954]: info: Plugin folders cleanup Dec 22 15:30:44 volumio volumio[9954]: info: Scanning into folder /volumio/app/plugins/ Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category audio_interface Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category miscellanea Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category music_service Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category plugins.json Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category system_controller Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category user_interface Dec 22 15:30:44 volumio volumio[9954]: info: Scanning into folder /data/plugins/ Dec 22 15:30:44 volumio volumio[9954]: info: Scanning category music_service Dec 22 15:30:44 volumio volumio[9954]: info: Plugin folders cleanup completed Dec 22 15:30:44 volumio volumio[9954]: info: ------------------------------------------- Dec 22 15:30:44 volumio volumio[9954]: info: ----- Core plugins startup ---- Dec 22 15:30:44 volumio volumio[9954]: info: ------------------------------------------- Dec 22 15:30:44 volumio volumio[9954]: info: Loading plugins from folder /volumio/app/plugins/ Dec 22 15:30:44 volumio volumio[9954]: info: Adding plugin upnp to MyMusic Plugins Dec 22 15:30:44 volumio volumio[9954]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 22 15:30:44 volumio volumio[9954]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 22 15:30:44 volumio volumio[9954]: info: Loading plugins from folder /data/plugins/ Dec 22 15:30:44 volumio volumio[9954]: info: Loading plugin "system"... Dec 22 15:30:44 volumio volumio[9954]: info: Loading plugin "appearance"... Dec 22 15:30:44 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:44 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32062. Dec 22 15:30:44 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:44 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:44 volumio volumio[9979]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:44 volumio volumio[9979]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:44 volumio volumio[9979]: Malformed config key: missing field `Authentication` Dec 22 15:30:44 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:44 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "network"... Dec 22 15:30:45 volumio volumio[9954]: info: Refreshing Cached IP Addresses Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "services"... Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "alsa_controller"... Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "wizard"... Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "volumio_command_line_client"... Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "upnp"... Dec 22 15:30:45 volumio volumio[9954]: info: [1671723045378] Starting Upmpd Daemon Dec 22 15:30:45 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "my_music"... Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "mpd"... Dec 22 15:30:45 volumio sudo[9982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:30:45 volumio sudo[9984]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:30:45 volumio sudo[9986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 22 15:30:45 volumio sudo[9984]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:45 volumio sudo[9986]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:45 volumio sudo[9986]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:45 volumio sudo[9984]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:45 volumio sudo[9982]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:45 volumio sudo[9982]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:45 volumio volumio[9954]: info: Creating MPD Configuration file Dec 22 15:30:45 volumio volumio[9954]: info: Loading plugin "upnp_browser"... Dec 22 15:30:45 volumio sudo[9993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:45 volumio sudo[9993]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:45 volumio sudo[9993]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:45 volumio sudo[9995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:45 volumio sudo[9995]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:45 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:45 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:45 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:45 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:46 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:46 volumio volumio[9954]: info: Loading plugin "networkfs"... Dec 22 15:30:46 volumio volumio[9954]: info: Starting Udev Watcher for removable devices Dec 22 15:30:46 volumio sudo[10003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nico,password=Fraise33,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/music /mnt/NAS/nestorNas Dec 22 15:30:46 volumio sudo[10003]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:46 volumio sudo[10003]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:46 volumio kernel: CIFS: Attempting to mount //192.168.1.16/music Dec 22 15:30:46 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 22 15:30:46 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 22 15:30:46 volumio volumio[9954]: info: Ignoring mount for partition: boot Dec 22 15:30:46 volumio volumio[9954]: info: Ignoring mount for partition: volumio Dec 22 15:30:46 volumio volumio[9954]: info: Ignoring mount for partition: volumio_data Dec 22 15:30:46 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:46 volumio volumio[9954]: info: Loading plugin "alarm-clock"... Dec 22 15:30:46 volumio volumio[9954]: info: Loading plugin "airplay_emulation"... Dec 22 15:30:47 volumio volumio[9954]: info: Starting Shairport Sync Dec 22 15:30:47 volumio volumio[9954]: info: Loading plugin "last_100"... Dec 22 15:30:47 volumio volumio[9954]: info: Loading plugin "webradio"... Dec 22 15:30:47 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:47 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32063. Dec 22 15:30:47 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:47 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:47 volumio volumio[10007]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:47 volumio volumio[10007]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:47 volumio volumio[10007]: Malformed config key: missing field `Authentication` Dec 22 15:30:47 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:47 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:47 volumio volumio[9954]: info: Loading plugin "i2s_dacs"... Dec 22 15:30:47 volumio volumio[9954]: info: Loading plugin "volumiodiscovery"... Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** For more information see Dec 22 15:30:47 volumio node[9954]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:47 volumio volumio[9954]: *** WARNING *** For more information see Dec 22 15:30:47 volumio node[9954]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:47 volumio node[9954]: *** WARNING *** For more information see Dec 22 15:30:47 volumio node[9954]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:30:47 volumio node[9954]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:30:47 volumio node[9954]: *** WARNING *** For more information see Dec 22 15:30:47 volumio volumio[9954]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 22 15:30:47 volumio volumio[9954]: info: Discovery: Started advertising with name: Volumio Dec 22 15:30:47 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:47 volumio volumio[9954]: info: Loading plugin "spop"... Dec 22 15:30:47 volumio mpd[10000]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:47 volumio mpd[10000]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:47 volumio mpd[10000]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:48 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:48 volumio sudo[9995]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:48 volumio volumio[9954]: info: Loading plugin "youtube2"... Dec 22 15:30:49 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:49 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32064. Dec 22 15:30:49 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:49 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:49 volumio volumio[10013]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:49 volumio volumio[10013]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:49 volumio volumio[10013]: Malformed config key: missing field `Authentication` Dec 22 15:30:49 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:49 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:50 volumio ntpd[656]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Dec 22 15:30:51 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:51 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32065. Dec 22 15:30:51 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:51 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:51 volumio volumio[10015]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:51 volumio volumio[10015]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:51 volumio volumio[10015]: Malformed config key: missing field `Authentication` Dec 22 15:30:51 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:51 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "outputs"... Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "albumart"... Dec 22 15:30:52 volumio volumio[9954]: info: Plugin example_plugin is not enabled Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "inputs"... Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "updater_comm"... Dec 22 15:30:52 volumio volumio[9954]: info: Plugin mpdemulation is not enabled Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "rest_api"... Dec 22 15:30:52 volumio volumio[9954]: info: Loading plugin "websocket"... Dec 22 15:30:52 volumio volumio[9954]: info: Loading i18n strings for locale fr Dec 22 15:30:52 volumio volumio[9954]: Updating browse sources language Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::initPlayerControls Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:52 volumio volumio[9954]: Express server listening on port 3000 Dec 22 15:30:52 volumio volumio[9954]: [Metrics] WebUI: 10s 189.48ms Dec 22 15:30:52 volumio volumio[9954]: info: CoreStateMachine::resetVolumioState Dec 22 15:30:52 volumio volumio[9954]: info: CoreStateMachine::getcurrentVolume Dec 22 15:30:52 volumio volumio[9954]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:53 volumio volumio[9954]: info: Cannot mount NAS nestorNas at system boot, trial number 1 ,retrying in 5 seconds Dec 22 15:30:53 volumio volumio[9954]: Forking 3 albumart workers Dec 22 15:30:53 volumio volumio[9954]: info: MPD Permissions set Dec 22 15:30:53 volumio volumio[9954]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Dec 22 15:30:53 volumio volumio[9954]: wlan0 Interface doesn't support scanning : Device or resource busy Dec 22 15:30:53 volumio volumio[9954]: info: Cannot use regular scanning, forcing with ap-force Dec 22 15:30:53 volumio wpa_supplicant[751]: wlan0: Failed to initiate sched scan Dec 22 15:30:53 volumio sudo[10049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Dec 22 15:30:53 volumio sudo[10049]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:53 volumio sudo[10049]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:53 volumio volumio[9954]: info: MPD running with PID10000 Dec 22 15:30:53 volumio volumio[9954]: ,establishing connection Dec 22 15:30:53 volumio volumio[9954]: info: CoreStateMachine::pushState Dec 22 15:30:53 volumio volumio[9954]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:53 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 15:30:53 volumio volumio[9954]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:53 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:53 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32066. Dec 22 15:30:53 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:53 volumio volumio[9954]: info: CoreStateMachine::updateTrackBlock Dec 22 15:30:53 volumio volumio[9954]: info: CorePlayQueue::getTrackBlock Dec 22 15:30:53 volumio volumio[9954]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:30:53 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:53 volumio volumio[10059]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:53 volumio volumio[10059]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:53 volumio volumio[10059]: Malformed config key: missing field `Authentication` Dec 22 15:30:53 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:53 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:53 volumio volumio[9954]: Starting albumart workers Dec 22 15:30:54 volumio volumio[9954]: Starting albumart workers Dec 22 15:30:54 volumio volumio[9954]: Starting albumart workers Dec 22 15:30:54 volumio volumio[9954]: error: MPD error: The expression evaluated to a falsy value: Dec 22 15:30:54 volumio volumio[9954]: assert.ok(self.idling) Dec 22 15:30:54 volumio volumio[9954]: error: MPD error: The expression evaluated to a falsy value: Dec 22 15:30:54 volumio volumio[9954]: assert.ok(self.idling) Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: Reloading queue from file Dec 22 15:30:54 volumio volumio[9954]: info: CoreStateMachine::pushState Dec 22 15:30:54 volumio volumio[9954]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:54 volumio volumio[9954]: info: Setting Device type: Raspberry PI Dec 22 15:30:54 volumio volumio[9954]: info: CoreStateMachine::setRepeat null single undefined Dec 22 15:30:54 volumio volumio[9954]: info: CoreStateMachine::pushState Dec 22 15:30:54 volumio volumio[9954]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:54 volumio volumio[9954]: info: CoreStateMachine::setRandom null Dec 22 15:30:54 volumio volumio[9954]: info: CoreStateMachine::pushState Dec 22 15:30:54 volumio volumio[9954]: info: CorePlayQueue::getTrack 0 Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::volumioPushState Dec 22 15:30:54 volumio volumio[9954]: error: updateQueue error: null Dec 22 15:30:54 volumio volumio[9954]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 22 15:30:54 volumio volumio[9954]: info: Completed loading Core Plugins Dec 22 15:30:54 volumio volumio[9954]: info: Preparing to generate the ALSA configuration file Dec 22 15:30:54 volumio volumio[9954]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 15:30:54 volumio volumio[9954]: info: Reading ALSA contributions from plugins. Dec 22 15:30:54 volumio volumio[9954]: info: Asound.conf file unchanged, so no further update is needed Dec 22 15:30:54 volumio volumio[9954]: info: Output device has changed, restarting MPD Dec 22 15:30:54 volumio volumio[9954]: info: Output device has changed, restarting Shairport Sync Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:54 volumio volumio[9954]: info: ___________ START PLUGINS ___________ Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:54 volumio volumio[9954]: info: [1671723054554] CoreMusicLibrary::Adding element Media Servers Dec 22 15:30:54 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:54 volumio volumio[9954]: Cannot find translation for sourceMedia Servers Dec 22 15:30:55 volumio sudo[10078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:30:55 volumio sudo[10078]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:55 volumio sudo[10076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:30:55 volumio sudo[10076]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:55 volumio sudo[10076]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:55 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:30:55 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:30:55 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:30:55 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:30:55 volumio volumio[9954]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:30:55 volumio volumio[9954]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:55 volumio volumio[9954]: info: [1671723055890] CoreMusicLibrary::Adding element Last_100 Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:55 volumio volumio[9954]: Cannot find translation for sourceMedia Servers Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:55 volumio volumio[9954]: info: [1671723055897] CoreMusicLibrary::Adding element Webradio Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:55 volumio volumio[9954]: Cannot find translation for sourceMedia Servers Dec 22 15:30:55 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 15:30:55 volumio volumio[9954]: info: Checking for old spotify connect plugin installed Dec 22 15:30:55 volumio volumio[9954]: info: [youtube2-auth] Starting auth flow... Dec 22 15:30:55 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:55 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32067. Dec 22 15:30:55 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:55 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:55 volumio volumio[10115]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:55 volumio volumio[10115]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:55 volumio volumio[10115]: Malformed config key: missing field `Authentication` Dec 22 15:30:55 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:55 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:30:56 volumio volumio[9954]: info: [1671723056041] CoreMusicLibrary::Adding element YouTube2 Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:30:56 volumio volumio[9954]: Cannot find translation for sourceMedia Servers Dec 22 15:30:56 volumio volumio[9954]: Cannot find translation for sourceYouTube2 Dec 22 15:30:56 volumio volumio[9954]: info: Volumio Calling Home Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:30:56 volumio volumio[9954]: [SpotifyConnect] Creating VLS config file Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:56 volumio volumio[9954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:30:56 volumio volumio[9954]: [SpotifyConnect] Starting metadata listener Dec 22 15:30:56 volumio sudo[10124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 22 15:30:56 volumio sudo[10124]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:56 volumio sudo[10127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:30:56 volumio sudo[10127]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:56 volumio volumio[9954]: Unhandled rejection Error: No sockets available, cannot start. Dec 22 15:30:56 volumio volumio[9954]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Dec 22 15:30:56 volumio volumio[9954]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Dec 22 15:30:56 volumio volumio[9954]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Dec 22 15:30:56 volumio volumio[9954]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Dec 22 15:30:56 volumio volumio[9954]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Dec 22 15:30:56 volumio volumio[9954]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Dec 22 15:30:56 volumio volumio[9954]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Dec 22 15:30:56 volumio volumio[9954]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Dec 22 15:30:56 volumio volumio[9954]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Dec 22 15:30:56 volumio volumio[9954]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Dec 22 15:30:56 volumio volumio[9954]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Dec 22 15:30:56 volumio volumio[9954]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Dec 22 15:30:56 volumio volumio[9954]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Dec 22 15:30:56 volumio volumio[9954]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Dec 22 15:30:56 volumio volumio[9954]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Dec 22 15:30:56 volumio volumio[9954]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Dec 22 15:30:56 volumio sudo[10127]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:56 volumio volumio[9954]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:56 volumio sudo[10130]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:30:56 volumio volumio[9954]: ReferenceError: deferred is not defined Dec 22 15:30:56 volumio volumio[9954]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Dec 22 15:30:56 volumio volumio[9954]: at ClientRequest.emit (events.js:315:20) Dec 22 15:30:56 volumio volumio[9954]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Dec 22 15:30:56 volumio volumio[9954]: at TLSSocket.emit (events.js:315:20) Dec 22 15:30:56 volumio volumio[9954]: at emitErrorNT (internal/streams/destroy.js:106:8) Dec 22 15:30:56 volumio volumio[9954]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Dec 22 15:30:56 volumio volumio[9954]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 22 15:30:56 volumio volumio[9954]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:30:56 volumio sudo[10130]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:56 volumio sudo[10130]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:57 volumio mpd[10121]: Dec 22 15:30 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:30:57 volumio mpd[10121]: Dec 22 15:30 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:30:57 volumio mpd[10121]: Dec 22 15:30 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:30:58 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:30:58 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32068. Dec 22 15:30:58 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:30:58 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:30:58 volumio sudo[10124]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:58 volumio volumio[10142]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:30:58 volumio volumio[10142]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:30:58 volumio volumio[10142]: Malformed config key: missing field `Authentication` Dec 22 15:30:58 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:58 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:30:58 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:30:58 volumio sudo[10078]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:58 volumio sudo[10141]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-12-22 15:29 Dec 22 15:30:58 volumio sudo[10141]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:30:58 volumio volumio-remote-updater[494]: [2022-12-22 15:30:58] [connect] Successful connection Dec 22 15:30:58 volumio sudo[10141]: pam_unix(sudo:session): session closed for user root Dec 22 15:30:58 volumio volumio-remote-updater[494]: [2022-12-22 15:30:58] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Dec 22 15:30:58 volumio volumio-remote-updater[494]: [2022-12-22 15:30:58] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Dec 22 15:30:58 volumio volumio-remote-updater[494]: [2022-12-22 15:30:58] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Dec 22 15:30:58 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:30:58 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 22 15:30:58 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:58 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:30:58 volumio wpa_supplicant[751]: wlan0: Trying to associate with SSID 'nestorBox' Dec 22 15:30:58 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Dec 22 15:30:58 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4508. Dec 22 15:30:58 volumio systemd[1]: Stopped Volumio Backend Module. Dec 22 15:30:58 volumio systemd[1]: Started Volumio Backend Module. Dec 22 15:30:58 volumio systemd[1]: Started dynamicswap service. Dec 22 15:30:58 volumio systemd[1]: dynamicswap.service: Succeeded. Dec 22 15:31:00 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:00 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32069. Dec 22 15:31:00 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:00 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:00 volumio volumio[10171]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:00 volumio volumio[10171]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:00 volumio volumio[10171]: Malformed config key: missing field `Authentication` Dec 22 15:31:00 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:00 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: carrier acquired Dec 22 15:31:00 volumio wpa_supplicant[751]: wlan0: Associated with 6c:b0:ce:24:81:ae Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: connected to Access Point `nestorBox' Dec 22 15:31:00 volumio wpa_supplicant[751]: wlan0: CTRL-EVENT-CONNECTED - Connection to 6c:b0:ce:24:81:ae completed [id=0 id_str=] Dec 22 15:31:00 volumio wpa_supplicant[751]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Dec 22 15:31:00 volumio dhcpcd[773]: DUID 00:01:00:01:2a:5e:eb:69:b8:27:eb:e7:4f:03 Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: IAID eb:b2:1a:56 Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: adding address fe80::4ad1:8fb8:46a6:7c7c Dec 22 15:31:00 volumio dhcpcd[773]: ipv6_addaddr1: Permission denied Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: carrier lost Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: carrier acquired Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: IAID eb:b2:1a:56 Dec 22 15:31:00 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:00 volumio volumio[10158]: info: ----- Volumio3 ---- Dec 22 15:31:00 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:00 volumio volumio[10158]: info: ----- System startup ---- Dec 22 15:31:00 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:00 volumio dhcpcd[773]: wlan0: rebinding lease of 192.168.1.6 Dec 22 15:31:01 volumio dhcpcd[773]: wlan0: probing address 192.168.1.6/24 Dec 22 15:31:01 volumio volumio[10158]: info: MYVOLUMIO Environment detected Dec 22 15:31:01 volumio volumio[10158]: info: Plugin folders cleanup Dec 22 15:31:01 volumio volumio[10158]: info: Scanning into folder /volumio/app/plugins/ Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category audio_interface Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category miscellanea Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category music_service Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category plugins.json Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category system_controller Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category user_interface Dec 22 15:31:01 volumio volumio[10158]: info: Scanning into folder /data/plugins/ Dec 22 15:31:01 volumio volumio[10158]: info: Scanning category music_service Dec 22 15:31:01 volumio volumio[10158]: info: Plugin folders cleanup completed Dec 22 15:31:01 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:01 volumio volumio[10158]: info: ----- Core plugins startup ---- Dec 22 15:31:01 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:01 volumio volumio[10158]: info: Loading plugins from folder /volumio/app/plugins/ Dec 22 15:31:01 volumio volumio[10158]: info: Adding plugin upnp to MyMusic Plugins Dec 22 15:31:01 volumio volumio[10158]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 22 15:31:01 volumio volumio[10158]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 22 15:31:01 volumio volumio[10158]: info: Loading plugins from folder /data/plugins/ Dec 22 15:31:01 volumio volumio[10158]: info: Loading plugin "system"... Dec 22 15:31:01 volumio volumio[10158]: info: Loading plugin "appearance"... Dec 22 15:31:01 volumio dhcpcd[773]: wlan0: soliciting an IPv6 router Dec 22 15:31:02 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:02 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32070. Dec 22 15:31:02 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:02 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:02 volumio volumio[10195]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:02 volumio volumio[10195]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:02 volumio volumio[10195]: Malformed config key: missing field `Authentication` Dec 22 15:31:02 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:02 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "network"... Dec 22 15:31:02 volumio volumio[10158]: info: Refreshing Cached IP Addresses Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "services"... Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "alsa_controller"... Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "wizard"... Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "volumio_command_line_client"... Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "upnp"... Dec 22 15:31:02 volumio volumio[10158]: info: [1671723062900] Starting Upmpd Daemon Dec 22 15:31:02 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "my_music"... Dec 22 15:31:02 volumio volumio[10158]: info: Loading plugin "mpd"... Dec 22 15:31:03 volumio sudo[10198]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:31:03 volumio sudo[10200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:31:03 volumio sudo[10202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Dec 22 15:31:03 volumio sudo[10202]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio sudo[10200]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio sudo[10198]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio sudo[10200]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:03 volumio sudo[10198]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:03 volumio volumio[10158]: info: Creating MPD Configuration file Dec 22 15:31:03 volumio volumio[10158]: info: Loading plugin "upnp_browser"... Dec 22 15:31:03 volumio sudo[10209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:31:03 volumio sudo[10209]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio sudo[10209]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:03 volumio sudo[10211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:31:03 volumio sudo[10211]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:31:03 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:31:03 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:31:03 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:31:03 volumio volumio[10158]: info: Loading plugin "networkfs"... Dec 22 15:31:03 volumio volumio[10158]: info: Starting Udev Watcher for removable devices Dec 22 15:31:03 volumio sudo[10219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=nico,password=Fraise33,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.16/music /mnt/NAS/nestorNas Dec 22 15:31:03 volumio sudo[10219]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:03 volumio kernel: CIFS: Attempting to mount //192.168.1.16/music Dec 22 15:31:03 volumio kernel: CIFS: VFS: Error connecting to socket. Aborting operation. Dec 22 15:31:03 volumio kernel: CIFS: VFS: cifs_mount failed w/return code = -101 Dec 22 15:31:03 volumio sudo[10219]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:04 volumio sudo[10202]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:04 volumio volumio[10158]: info: Ignoring mount for partition: boot Dec 22 15:31:04 volumio volumio[10158]: info: Ignoring mount for partition: volumio Dec 22 15:31:04 volumio volumio[10158]: info: Ignoring mount for partition: volumio_data Dec 22 15:31:04 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "alarm-clock"... Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "airplay_emulation"... Dec 22 15:31:04 volumio volumio[10158]: info: Starting Shairport Sync Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "last_100"... Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "webradio"... Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "i2s_dacs"... Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "volumiodiscovery"... Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:31:04 volumio node[10158]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:31:04 volumio node[10158]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** For more information see Dec 22 15:31:04 volumio node[10158]: *** WARNING *** For more information see Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:31:04 volumio node[10158]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:31:04 volumio node[10158]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 22 15:31:04 volumio volumio[10158]: *** WARNING *** For more information see Dec 22 15:31:04 volumio node[10158]: *** WARNING *** For more information see Dec 22 15:31:04 volumio volumio[10158]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 22 15:31:04 volumio volumio[10158]: info: Discovery: Started advertising with name: Volumio Dec 22 15:31:04 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:31:04 volumio volumio[10158]: info: Loading plugin "spop"... Dec 22 15:31:04 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:04 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32071. Dec 22 15:31:04 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:04 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:04 volumio volumio[10225]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:04 volumio volumio[10225]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:04 volumio volumio[10225]: Malformed config key: missing field `Authentication` Dec 22 15:31:04 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:04 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:04 volumio mpd[10216]: Dec 22 15:31 : exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:31:05 volumio mpd[10216]: Dec 22 15:31 : exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:31:05 volumio mpd[10216]: Dec 22 15:31 : exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:31:05 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:31:05 volumio volumio[10158]: info: Loading plugin "youtube2"... Dec 22 15:31:05 volumio sudo[10211]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:06 volumio dhcpcd[773]: wlan0: leased 192.168.1.6 for 86400 seconds Dec 22 15:31:06 volumio avahi-daemon[502]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.6. Dec 22 15:31:06 volumio dhcpcd[773]: wlan0: adding route to 192.168.1.0/24 Dec 22 15:31:06 volumio dhcpcd[773]: wlan0: adding default route via 192.168.1.1 Dec 22 15:31:06 volumio avahi-daemon[502]: New relevant interface wlan0.IPv4 for mDNS. Dec 22 15:31:06 volumio avahi-daemon[502]: Registering new address record for 192.168.1.6 on wlan0.IPv4. Dec 22 15:31:07 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:07 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32072. Dec 22 15:31:07 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:07 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:07 volumio volumio[10249]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:07 volumio volumio[10249]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:07 volumio volumio[10249]: Malformed config key: missing field `Authentication` Dec 22 15:31:07 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:07 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:08 volumio ntpd[656]: Listen normally on 3 wlan0 192.168.1.6:123 Dec 22 15:31:08 volumio ntpd[656]: new interface(s) found: waking up resolver Dec 22 15:31:08 volumio volumio-remote-updater[494]: [2022-12-22 15:31:08] [connect] Successful connection Dec 22 15:31:09 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:09 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32073. Dec 22 15:31:09 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:09 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:09 volumio volumio[10251]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:09 volumio volumio[10251]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:09 volumio volumio[10251]: Malformed config key: missing field `Authentication` Dec 22 15:31:09 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:09 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "outputs"... Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "albumart"... Dec 22 15:31:10 volumio volumio[10158]: info: Plugin example_plugin is not enabled Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "inputs"... Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "updater_comm"... Dec 22 15:31:10 volumio volumio[10158]: info: Plugin mpdemulation is not enabled Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "rest_api"... Dec 22 15:31:10 volumio volumio[10158]: info: Loading plugin "websocket"... Dec 22 15:31:10 volumio volumio[10158]: info: Loading i18n strings for locale fr Dec 22 15:31:10 volumio volumio[10158]: Updating browse sources language Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::initPlayerControls Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: Express server listening on port 3000 Dec 22 15:31:10 volumio volumio[10158]: [Metrics] WebUI: 10s 253.78ms Dec 22 15:31:10 volumio volumio[10158]: info: CoreStateMachine::resetVolumioState Dec 22 15:31:10 volumio volumio[10158]: info: CoreStateMachine::getcurrentVolume Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:31:10 volumio volumio[10158]: info: Cannot mount NAS nestorNas at system boot, trial number 1 ,retrying in 5 seconds Dec 22 15:31:10 volumio volumio[10158]: Forking 3 albumart workers Dec 22 15:31:10 volumio volumio[10158]: info: MPD Permissions set Dec 22 15:31:10 volumio volumio-remote-updater[494]: [2022-12-22 15:31:10] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1671723068 101 Dec 22 15:31:10 volumio volumio[10158]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 1 Dec 22 15:31:10 volumio volumio[10158]: info: CoreStateMachine::pushState Dec 22 15:31:10 volumio volumio[10158]: info: CorePlayQueue::getTrack 0 Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::volumioPushState Dec 22 15:31:10 volumio volumio[10158]: info: CoreStateMachine::updateTrackBlock Dec 22 15:31:10 volumio ntpd[656]: Soliciting pool server 212.25.15.128 Dec 22 15:31:10 volumio volumio[10158]: info: CorePlayQueue::getTrackBlock Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::volumioRetrievevolume Dec 22 15:31:10 volumio volumio[10158]: info: MPD running with PID10216 Dec 22 15:31:10 volumio volumio[10158]: ,establishing connection Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:10 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:11 volumio volumio[10158]: info: Reloading queue from file Dec 22 15:31:11 volumio volumio[10158]: error: updateQueue error: null Dec 22 15:31:11 volumio volumio[10158]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 22 15:31:11 volumio volumio[10158]: info: CoreStateMachine::setRepeat null single undefined Dec 22 15:31:11 volumio volumio[10158]: info: CoreStateMachine::pushState Dec 22 15:31:11 volumio volumio[10158]: info: CorePlayQueue::getTrack 0 Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::volumioPushState Dec 22 15:31:11 volumio volumio[10158]: info: CoreStateMachine::setRandom null Dec 22 15:31:11 volumio volumio[10158]: info: CoreStateMachine::pushState Dec 22 15:31:11 volumio volumio[10158]: info: CorePlayQueue::getTrack 0 Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::volumioPushState Dec 22 15:31:11 volumio volumio[10158]: info: Setting Device type: Raspberry PI Dec 22 15:31:11 volumio volumio[10158]: info: Completed loading Core Plugins Dec 22 15:31:11 volumio volumio[10158]: info: Preparing to generate the ALSA configuration file Dec 22 15:31:11 volumio volumio[10158]: info: CoreStateMachine::pushState Dec 22 15:31:11 volumio volumio[10158]: info: CorePlayQueue::getTrack 0 Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::volumioPushState Dec 22 15:31:11 volumio volumio[10158]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Dec 22 15:31:11 volumio volumio[10158]: info: Reading ALSA contributions from plugins. Dec 22 15:31:11 volumio ntpd[656]: Soliciting pool server 156.106.214.48 Dec 22 15:31:11 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:11 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32074. Dec 22 15:31:11 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:11 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:11 volumio volumio[10307]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:11 volumio volumio[10307]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:11 volumio volumio[10307]: Malformed config key: missing field `Authentication` Dec 22 15:31:11 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:11 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:11 volumio volumio[10158]: info: Discovery: adding 3ea848ef-c65b-4d79-8abc-bdc8d6398146 Dec 22 15:31:11 volumio volumio[10158]: info: mDNS: Found device Volumio Dec 22 15:31:11 volumio volumio[10158]: info: CoreCommandRouter::volumioGetState Dec 22 15:31:11 volumio volumio[10158]: info: CorePlayQueue::getTrack 0 Dec 22 15:31:11 volumio volumio[10158]: Starting albumart workers Dec 22 15:31:11 volumio volumio[10158]: Starting albumart workers Dec 22 15:31:11 volumio volumio[10158]: error: updateQueue error: null Dec 22 15:31:11 volumio volumio[10158]: Starting albumart workers Dec 22 15:31:12 volumio ntpd[656]: Soliciting pool server 130.60.204.10 Dec 22 15:31:12 volumio volumio[10158]: info: Asound.conf file unchanged, so no further update is needed Dec 22 15:31:12 volumio volumio[10158]: info: Output device has changed, restarting MPD Dec 22 15:31:12 volumio volumio[10158]: info: Output device has changed, restarting Shairport Sync Dec 22 15:31:12 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:12 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:12 volumio volumio[10158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:31:12 volumio volumio[10158]: info: ___________ START PLUGINS ___________ Dec 22 15:31:12 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 22 15:31:12 volumio volumio[10158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:31:12 volumio volumio[10158]: info: [1671723072667] CoreMusicLibrary::Adding element Media Servers Dec 22 15:31:12 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:31:12 volumio volumio[10158]: Cannot find translation for sourceMedia Servers Dec 22 15:31:13 volumio ntpd[656]: Soliciting pool server 192.33.214.47 Dec 22 15:31:13 volumio sudo[10312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 22 15:31:13 volumio sudo[10310]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 22 15:31:13 volumio sudo[10312]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:13 volumio sudo[10310]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:13 volumio sudo[10310]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:13 volumio systemd[1]: Stopping Music Player Daemon... Dec 22 15:31:13 volumio systemd[1]: mpd.service: Succeeded. Dec 22 15:31:13 volumio systemd[1]: Stopped Music Player Daemon. Dec 22 15:31:13 volumio systemd[1]: Starting Music Player Daemon... Dec 22 15:31:13 volumio ntpd[656]: Soliciting pool server 217.147.208.1 Dec 22 15:31:13 volumio ntpd[656]: Soliciting pool server 84.16.73.33 Dec 22 15:31:13 volumio volumio[10158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:31:13 volumio volumio[10158]: info: [1671723073450] CoreMusicLibrary::Adding element Last_100 Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:31:13 volumio volumio[10158]: Cannot find translation for sourceMedia Servers Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:31:13 volumio volumio[10158]: info: [1671723073455] CoreMusicLibrary::Adding element Webradio Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:31:13 volumio volumio[10158]: Cannot find translation for sourceMedia Servers Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 22 15:31:13 volumio volumio[10158]: info: Checking for old spotify connect plugin installed Dec 22 15:31:13 volumio volumio[10158]: info: [youtube2-auth] Starting auth flow... Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 22 15:31:13 volumio volumio[10158]: info: [1671723073577] CoreMusicLibrary::Adding element YouTube2 Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 22 15:31:13 volumio volumio[10158]: Cannot find translation for sourceMedia Servers Dec 22 15:31:13 volumio volumio[10158]: Cannot find translation for sourceYouTube2 Dec 22 15:31:13 volumio volumio[10158]: info: Volumio Calling Home Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 22 15:31:13 volumio volumio[10158]: [SpotifyConnect] Creating VLS config file Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:13 volumio volumio[10158]: [SpotifyConnect] Starting metadata listener Dec 22 15:31:13 volumio sudo[10355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Dec 22 15:31:13 volumio sudo[10355]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:13 volumio systemd[1]: volspotconnect.service: Service RestartSec=2s expired, scheduling restart. Dec 22 15:31:13 volumio systemd[1]: volspotconnect.service: Scheduled restart job, restart counter is at 32075. Dec 22 15:31:13 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Dec 22 15:31:13 volumio systemd[1]: Started Volspotconnect2 Daemon. Dec 22 15:31:13 volumio volumio[10357]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Dec 22 15:31:13 volumio volumio[10357]: Reading Config from "/tmp/volspotify.toml" Dec 22 15:31:13 volumio volumio[10357]: Malformed config key: missing field `Authentication` Dec 22 15:31:13 volumio systemd[1]: volspotconnect.service: Main process exited, code=exited, status=1/FAILURE Dec 22 15:31:13 volumio sudo[10355]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:13 volumio systemd[1]: volspotconnect.service: Failed with result 'exit-code'. Dec 22 15:31:14 volumio sudo[10360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 22 15:31:14 volumio sudo[10360]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:14 volumio sudo[10360]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:14 volumio sudo[10363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 22 15:31:14 volumio sudo[10363]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 22 15:31:14 volumio sudo[10363]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:14 volumio volumio[10158]: [SpotifyConnect] Vollibrespot Daemon service started! Dec 22 15:31:14 volumio volumio[10158]: [Metrics] SpotifyConnect: 0s 353.95ms Dec 22 15:31:14 volumio volumio[10158]: info: Completed starting Core Plugins Dec 22 15:31:14 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:14 volumio volumio[10158]: info: ----- MyVolumio plugins startup ---- Dec 22 15:31:14 volumio volumio[10158]: info: ------------------------------------------- Dec 22 15:31:14 volumio volumio[10158]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 22 15:31:14 volumio volumio[10158]: info: MPD Permissions set Dec 22 15:31:14 volumio volumio[10158]: info: Volumio called home Dec 22 15:31:14 volumio volumio[10158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 2 Dec 22 15:31:14 volumio volumio[10158]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 22 15:31:14 volumio volumio[10158]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:31:14 volumio volumio[10158]: ReferenceError: deferred is not defined Dec 22 15:31:14 volumio volumio[10158]: at ClientRequest. (/data/plugins/music_service/youtube2/lib/core/gapi/auth.js:155:13) Dec 22 15:31:14 volumio volumio[10158]: at ClientRequest.emit (events.js:315:20) Dec 22 15:31:14 volumio volumio[10158]: at TLSSocket.socketErrorListener (_http_client.js:469:9) Dec 22 15:31:14 volumio volumio[10158]: at TLSSocket.emit (events.js:315:20) Dec 22 15:31:14 volumio volumio[10158]: at emitErrorNT (internal/streams/destroy.js:106:8) Dec 22 15:31:14 volumio volumio[10158]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) Dec 22 15:31:14 volumio volumio[10158]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 22 15:31:14 volumio volumio[10158]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 22 15:31:14 volumio ntpd[656]: Soliciting pool server 84.73.226.160 Dec 22 15:31:14 volumio mpd[10351]: exception: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 22 15:31:14 volumio mpd[10351]: output: No 'audio_output' defined in config file Dec 22 15:31:14 volumio mpd[10351]: output: Attempt to detect audio output device Dec 22 15:31:14 volumio mpd[10351]: output: Attempting to detect a alsa audio device Dec 22 15:31:14 volumio mpd[10351]: output: Successfully detected a alsa audio device Dec 22 15:31:14 volumio mpd[10351]: exception: Input plugin 'tidal' is unavailable: No Tidal application token configured Dec 22 15:31:14 volumio mpd[10351]: exception: Input plugin 'qobuz' is unavailable: No Qobuz app_id configured Dec 22 15:31:15 volumio mpd[10351]: zeroconf: No global port, disabling zeroconf Dec 22 15:31:15 volumio systemd[1]: Started Music Player Daemon. Dec 22 15:31:15 volumio sudo[10312]: pam_unix(sudo:session): session closed for user root Dec 22 15:31:15 volumio sudo[10378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2022-12-22 15:30 Dec 22 15:31:15 volumio sudo[10378]: 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="1f061e035f7cb2799b32d3520aa8e55cd07df6f9" VOLUMIO_FE_VERSION="9971a09df9c3edfdedf2ecf438999be8aba9db68" VOLUMIO_FE3_VERSION="3974def988c7b2392ddc85f9b8cb4692d5e8fda9" VOLUMIO_BE_VERSION="b3c53a818b9b3d0e5c13c9d346c4d613c4ca426f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 11 Jul 2022 04:03:33 PM CEST" VOLUMIO_VERSION="3.324" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5b2f59e6e90e57f326ca25c7ca839d52"