-- Logs begin at Thu 2019-02-14 02:11:58 PST, end at Fri 2024-06-28 17:41:58 PDT. -- Jun 28 17:40:09 volumio volumio-remote-updater[779]: [2024-06-28 17:40:09] [connect] Successful connection Jun 28 17:40:15 volumio ntpd[1031]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Jun 28 17:40:22 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jun 28 17:40:22 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jun 28 17:40:22 volumio systemd[1]: Started dynamicswap service. Jun 28 17:40:22 volumio systemd[1]: dynamicswap.service: Succeeded. Jun 28 17:40:22 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jun 28 17:40:22 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 10. Jun 28 17:40:22 volumio systemd[1]: Stopped Volumio Backend Module. Jun 28 17:40:22 volumio systemd[1]: Started Volumio Backend Module. Jun 28 17:40:22 volumio systemd[1]: Started dynamicswap service. Jun 28 17:40:22 volumio systemd[1]: dynamicswap.service: Succeeded. Jun 28 17:40:22 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:22 volumio volumio[4197]: info: ----- Volumio3 ---- Jun 28 17:40:22 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:22 volumio volumio[4197]: info: ----- System startup ---- Jun 28 17:40:22 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:22 volumio volumio[4197]: info: MYVOLUMIO Environment detected Jun 28 17:40:22 volumio volumio[4197]: info: Plugin folders cleanup Jun 28 17:40:22 volumio volumio[4197]: info: Scanning into folder /volumio/app/plugins/ Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category audio_interface Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category miscellanea Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category music_service Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category plugins.json Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category system_controller Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category user_interface Jun 28 17:40:22 volumio volumio[4197]: info: Scanning into folder /data/plugins/ Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category audio_interface Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category music_service Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category system_controller Jun 28 17:40:22 volumio volumio[4197]: info: Scanning category user_interface Jun 28 17:40:22 volumio volumio[4197]: info: Plugin folders cleanup completed Jun 28 17:40:22 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:22 volumio volumio[4197]: info: ----- Core plugins startup ---- Jun 28 17:40:22 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugins from folder /volumio/app/plugins/ Jun 28 17:40:22 volumio volumio[4197]: info: Adding plugin upnp to MyMusic Plugins Jun 28 17:40:22 volumio volumio[4197]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 28 17:40:22 volumio volumio[4197]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugins from folder /data/plugins/ Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugin "system"... Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugin "appearance"... Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugin "network"... Jun 28 17:40:22 volumio volumio[4197]: info: Refreshing Cached IP Addresses Jun 28 17:40:22 volumio sudo[4226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 17:40:22 volumio sudo[4226]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugin "services"... Jun 28 17:40:22 volumio sudo[4226]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:22 volumio volumio[4197]: info: Loading plugin "alsa_controller"... Jun 28 17:40:22 volumio sudo[4228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 17:40:22 volumio sudo[4228]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:22 volumio sudo[4228]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "wizard"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "networkfs"... Jun 28 17:40:23 volumio volumio[4197]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 1 ,retrying in 5 seconds Jun 28 17:40:23 volumio volumio[4197]: info: Starting Udev Watcher for removable devices Jun 28 17:40:23 volumio volumio[4197]: info: Ignoring mount for partition: boot Jun 28 17:40:23 volumio volumio[4197]: info: Ignoring mount for partition: volumio Jun 28 17:40:23 volumio volumio[4197]: info: Ignoring mount for partition: volumio_data Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "volumio_command_line_client"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "upnp"... Jun 28 17:40:23 volumio volumio[4197]: info: [1719621623029] Starting Upmpd Daemon Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "my_music"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "mpd"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "upnp_browser"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "alarm-clock"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "airplay_emulation"... Jun 28 17:40:23 volumio volumio[4197]: info: Starting Shairport Sync Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "last_100"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "webradio"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "i2s_dacs"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "volumiodiscovery"... Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 17:40:23 volumio node[4197]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:40:23 volumio node[4197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** For more information see Jun 28 17:40:23 volumio node[4197]: *** WARNING *** For more information see Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 17:40:23 volumio node[4197]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:40:23 volumio node[4197]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:40:23 volumio volumio[4197]: *** WARNING *** For more information see Jun 28 17:40:23 volumio node[4197]: *** WARNING *** For more information see Jun 28 17:40:23 volumio volumio[4197]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 28 17:40:23 volumio volumio[4197]: info: Discovery: Started advertising with name: Volumio Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:40:23 volumio volumio[4197]: info: Plugin squeezelite_mc is not enabled Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "outputs"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "albumart"... Jun 28 17:40:23 volumio volumio[4197]: info: Plugin example_plugin is not enabled Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "inputs"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "updater_comm"... Jun 28 17:40:23 volumio volumio[4197]: info: Plugin mpdemulation is not enabled Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "rest_api"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "websocket"... Jun 28 17:40:23 volumio volumio[4197]: info: Starting Socket.io Server version 2.3.0 Jun 28 17:40:23 volumio volumio[4197]: info: Plugin fusiondsp is not enabled Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "lms"... Jun 28 17:40:23 volumio volumio[4197]: Forking 3 albumart workers Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "pandora"... Jun 28 17:40:23 volumio volumio[4197]: Starting albumart workers Jun 28 17:40:23 volumio volumio[4197]: Starting albumart workers Jun 28 17:40:23 volumio volumio[4197]: info: Applying required configuration parameters for plugin pandora Jun 28 17:40:23 volumio volumio[4197]: Starting albumart workers Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "podcast"... Jun 28 17:40:23 volumio volumio[4197]: info: ControllerPodcast::constructor Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "backup_restore"... Jun 28 17:40:23 volumio volumio[4197]: info: Applying required configuration parameters for plugin backup_restore Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "Systeminfo"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading plugin "lastfm"... Jun 28 17:40:23 volumio volumio[4197]: info: Loading i18n strings for locale en Jun 28 17:40:23 volumio volumio[4197]: Updating browse sources language Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::initPlayerControls Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: Express server listening on port 3000 Jun 28 17:40:23 volumio volumio[4197]: [Metrics] WebUI: 1s 423.35ms Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::resetVolumioState Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::getcurrentVolume Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 17:40:23 volumio volumio[4197]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:23 volumio volumio[4197]: info: Reloading queue from file Jun 28 17:40:23 volumio volumio[4197]: info: VolumeController:: Volume=100 Mute =false Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::pushState Jun 28 17:40:23 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::volumioPushState Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::updateTrackBlock Jun 28 17:40:23 volumio volumio[4197]: info: CorePlayQueue::getTrackBlock Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::setRepeat null single undefined Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::pushState Jun 28 17:40:23 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::volumioPushState Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::setRandom null Jun 28 17:40:23 volumio volumio[4197]: info: CoreStateMachine::pushState Jun 28 17:40:23 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:23 volumio volumio[4197]: info: CoreCommandRouter::volumioPushState Jun 28 17:40:23 volumio volumio[4197]: info: Setting Device type: Raspberry PI Jun 28 17:40:23 volumio volumio[4197]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 28 17:40:23 volumio volumio[4197]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Jun 28 17:40:23 volumio volumio[4197]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 28 17:40:23 volumio volumio[4197]: info: Completed loading Core Plugins Jun 28 17:40:23 volumio volumio[4197]: info: Preparing to generate the ALSA configuration file Jun 28 17:40:24 volumio volumio[4197]: info: VolumeController:: Volume=100 Mute =false Jun 28 17:40:24 volumio volumio[4197]: info: CoreStateMachine::pushState Jun 28 17:40:24 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioPushState Jun 28 17:40:24 volumio volumio[4197]: info: Asound.conf file unchanged, so no further update is needed Jun 28 17:40:24 volumio volumio[4197]: info: Output device has changed, restarting MPD Jun 28 17:40:24 volumio sudo[4303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 17:40:24 volumio sudo[4303]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio sudo[4303]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: Output device has changed, restarting Shairport Sync Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio sudo[4306]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 17:40:24 volumio sudo[4306]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio systemd[1]: Stopping Music Player Daemon... Jun 28 17:40:24 volumio volumio[4197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:40:24 volumio volumio[4197]: info: ___________ START PLUGINS ___________ Jun 28 17:40:24 volumio volumio[4197]: info: ControllerMpd::onStart: Initializing MPD Jun 28 17:40:24 volumio volumio[4197]: info: Creating MPD Configuration file Jun 28 17:40:24 volumio sudo[4312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 17:40:24 volumio sudo[4312]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio sudo[4312]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624072] CoreMusicLibrary::Adding element Media Servers Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio sudo[4315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 17:40:24 volumio sudo[4315]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio systemd[1]: mpd.service: Succeeded. Jun 28 17:40:24 volumio systemd[1]: Stopped Music Player Daemon. Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio systemd[1]: Starting Music Player Daemon... Jun 28 17:40:24 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jun 28 17:40:24 volumio systemd[1]: mpd.service: Succeeded. Jun 28 17:40:24 volumio systemd[1]: Stopped Music Player Daemon. Jun 28 17:40:24 volumio systemd[1]: Starting Music Player Daemon... Jun 28 17:40:24 volumio volumio[4197]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624109] CoreMusicLibrary::Adding element Last_100 Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624110] CoreMusicLibrary::Adding element Webradio Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:40:24 volumio volumio[4197]: info: Initializing BBC Radios Jun 28 17:40:24 volumio sudo[4324]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 17:40:24 volumio sudo[4324]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio sudo[4324]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624143] CoreMusicLibrary::Adding element Pandora Radio Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source Pandora Radio Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624143] ControllerPandora::initializeMQTT Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624144] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624145] CoreMusicLibrary::Adding element Podcast Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source Pandora Radio Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source Podcast Jun 28 17:40:24 volumio sudo[4338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624146] CoreMusicLibrary::Adding element LastFM Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source Pandora Radio Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source Podcast Jun 28 17:40:24 volumio volumio[4197]: Cannot find translation for source LastFM Jun 28 17:40:24 volumio sudo[4338]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio volumio[4197]: info: [LastFM] scrobbler initiated! Jun 28 17:40:24 volumio volumio[4197]: info: [LastFM] extended logging: false Jun 28 17:40:24 volumio volumio[4197]: info: [LastFM] try scrobble stream/radio plays: true Jun 28 17:40:24 volumio volumio[4197]: info: [LastFM] Left init routine Jun 28 17:40:24 volumio volumio[4197]: info: [LastFM] Socket already connected: true Jun 28 17:40:24 volumio volumio[4197]: info: Volumio Calling Home Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.155] Stop:1575 stopping squeezelite devices ... Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.155] slimproto_close:957 [0x178730] slimproto stop for Volumio-UPnP/AV Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.157] sighandler:1619 Please wait for clean exit! Jun 28 17:40:24 volumio systemd[1]: Stopping Logitech Media Server... Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624172] ControllerPandora::initialSetup Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624173] ControllerPandora::PandoraHandler::init Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624173] ControllerPandora::PandoraHandler::loadErrorCodes Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624176] [Pandora] PandoraHandler::setMaxStationTracks: 16 Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624176] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624176] ControllerPandora::flushPandora Jun 28 17:40:24 volumio volumio[4197]: info: CorePlayQueue::getQueue Jun 28 17:40:24 volumio volumio[4197]: info: CorePlayQueue::clearAddPlayQueue Jun 28 17:40:24 volumio volumio[4197]: info: CorePlayQueue::saveQueue Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::serviceClearAddPlayTracks Jun 28 17:40:24 volumio volumio[4197]: error: WARNING: No clearAddPlayTracks method for service webradio Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::volumioPushQueue Jun 28 17:40:24 volumio volumio[4197]: info: [1719621624178] ControllerPandora::validateAndSetAccountOptions Jun 28 17:40:24 volumio volumio[4197]: error: [1719621624178] [Pandora] validateAndSetAccountOptions: Need email address and password. See plugin settings. Jun 28 17:40:24 volumio volumio[4197]: info: MPD Permissions set Jun 28 17:40:24 volumio volumio[4197]: info: MPD Permissions set Jun 28 17:40:24 volumio volumio[4197]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:24 volumio volumio[4197]: info: Starting Shairport Sync Jun 28 17:40:24 volumio volumio[4197]: info: Starting Shairport Sync Jun 28 17:40:24 volumio sudo[4353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:40:24 volumio sudo[4353]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio volumio[4197]: info: Starting Shairport Sync Jun 28 17:40:24 volumio sudo[4356]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:40:24 volumio sudo[4356]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 17:40:24 volumio sudo[4359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:40:24 volumio sudo[4359]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:24 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 28 17:40:24 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 17:40:24 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 17:40:24 volumio sudo[4356]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: Shairport-Sync Started Jun 28 17:40:24 volumio volumio[4197]: Error adding Membership: Error: addMembership EINVAL Jun 28 17:40:24 volumio sudo[4359]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: Shairport-Sync Started Jun 28 17:40:24 volumio sudo[4353]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: Shairport-Sync Started Jun 28 17:40:24 volumio mpd[4333]: Jun 28 17:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.424] Stop:1579 terminate update thread ... Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.425] Stop:1584 terminate main thread ... Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.425] Stop:1587 stopping UPnP devices ... Jun 28 17:40:24 volumio squeezeboxserver[4083]: [17:40:24.427] sighandler:1633 all done - exit through signal Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:14.7534] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:16.1751] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:16.1970] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.1548] Plugins::Live365::Plugin::__ANON__ (174) Failed to get initial page from Live365.com - error: Couldn't resolve IP address for: live365.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.2463] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting https://www.mysqueezebox.com/api/sounds/v1/opml Jun 28 17:40:24 volumio squeezeboxserver[4083]: Couldn't resolve IP address for: www.mysqueezebox.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.2469] Slim::Plugin::Sounds::Plugin::_gotSoundsError (82) Error: Unable to cache Sounds & Effects menu from SN: Couldn't resolve IP address for: www.mysqueezebox.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.3065] Slim::Networking::Repositories::__ANON__ (147) Failed to fetch https://github.com/LMS-Community/lms-plugin-repository/raw/master/extensions.xml: Couldn't resolve IP address for: github.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.3367] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:40:24 volumio squeezeboxserver[4083]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:24.3373] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:44.0060] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:40:24 volumio squeezeboxserver[4083]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:39:44.0062] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:40:14.0075] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:40:24 volumio squeezeboxserver[4083]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio squeezeboxserver[4083]: [24-06-28 17:40:14.0077] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:40:24 volumio systemd[1]: logitechmediaserver.service: Succeeded. Jun 28 17:40:24 volumio systemd[1]: Stopped Logitech Media Server. Jun 28 17:40:24 volumio systemd[1]: Started Logitech Media Server. Jun 28 17:40:24 volumio sudo[4338]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: logitechmediaserver started Jun 28 17:40:24 volumio volumio-remote-updater[779]: [2024-06-28 17:40:24] [connect] Successful connection Jun 28 17:40:24 volumio volumio-remote-updater[779]: [2024-06-28 17:40:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1719621624 101 Jun 28 17:40:24 volumio volumio[4197]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Jun 28 17:40:24 volumio systemd[1]: Started Music Player Daemon. Jun 28 17:40:24 volumio sudo[4315]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio sudo[4306]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:24 volumio volumio[4197]: info: Completed starting Core Plugins Jun 28 17:40:24 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:24 volumio volumio[4197]: info: ----- MyVolumio plugins startup ---- Jun 28 17:40:24 volumio volumio[4197]: info: ------------------------------------------- Jun 28 17:40:24 volumio volumio[4197]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 28 17:40:24 volumio volumio[4197]: error: MPD error: The expression evaluated to a falsy value: Jun 28 17:40:24 volumio volumio[4197]: assert.ok(self.idling) Jun 28 17:40:24 volumio volumio[4197]: error: The expression evaluated to a falsy value: Jun 28 17:40:24 volumio volumio[4197]: assert.ok(self.idling) Jun 28 17:40:24 volumio volumio[4197]: error: updateQueue error: null Jun 28 17:40:24 volumio volumio[4197]: info: MPD running with PID4333 Jun 28 17:40:24 volumio volumio[4197]: ,establishing connection Jun 28 17:40:24 volumio volumio[4197]: error: updateQueue error: null Jun 28 17:40:25 volumio squeezeboxserver[4367]: [24-06-28 17:40:25.0497] main::init (377) Starting Logitech Media Server (v8.3.0, 1667251155, Fri 04 Nov 2022 09:17:53 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Jun 28 17:40:25 volumio squeezeboxserver[4367]: [17:40:25.432] main:1831 Starting squeeze2upnp version: v3.3.9 (Apr 5 2024 @ 22:09:49) Jun 28 17:40:25 volumio squeezeboxserver[4367]: [17:40:25.486] Start:1530 Binding to iface 192.168.88.24:49152 [eth0] (http port 0) Jun 28 17:40:25 volumio squeezeboxserver[4367]: [17:40:25.486] Start:1566 UPnP search for urn:schemas-upnp-org:device:MediaRenderer:1 Jun 28 17:40:25 volumio squeezeboxserver[4367]: [17:40:25.687] Start:1566 UPnP search for urn:schemas-upnp-org:device:MediaRenderer:2 Jun 28 17:40:27 volumio volumio[4197]: info: CoreCommandRouter::volumioGetState Jun 28 17:40:27 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:27 volumio volumio[4197]: info: Listing playlists Jun 28 17:40:27 volumio volumio[4197]: info: Listing playlists Jun 28 17:40:28 volumio volumio[4197]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 2 ,retrying in 5 seconds Jun 28 17:40:29 volumio volumio[4197]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 28 17:40:33 volumio volumio[4197]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 3 ,retrying in 5 seconds Jun 28 17:40:33 volumio sudo[4388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 17:40:33 volumio sudo[4388]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:33 volumio sudo[4388]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:33 volumio sudo[4391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 17:40:33 volumio sudo[4391]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:33 volumio sudo[4391]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:37 volumio volumio[4197]: Cannot compose Albumart path Jun 28 17:40:37 volumio sudo[4394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 28 17:40:37 volumio sudo[4394]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:37 volumio sudo[4394]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:37 volumio volumio[4197]: info: Upmpdcli Daemon Started Jun 28 17:40:37 volumio volumio[4197]: info: CoreCommandRouter::volumioGetState Jun 28 17:40:37 volumio volumio[4197]: info: CorePlayQueue::getTrack 0 Jun 28 17:40:38 volumio ntpd[1031]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 28 17:40:38 volumio volumio[4197]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 4 ,retrying in 5 seconds Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.759] AddMRDevice:1455 [0x1f5290]: adding renderer (Volumio-UPnP/AV) 192.168.88.24 with mac BBBB-F107F44E Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.761] MasterHandler:1075 [0x1f5290]: subscribe success Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.762] slimproto:885 squeezelite [0x178730] <=> player [0x1f5290] Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.762] slimproto:886 [0x178730] connecting to 192.168.88.24:3483 Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.762] slimproto:916 [0x178730] connected Jun 28 17:40:38 volumio squeezeboxserver[4367]: [17:40:38.762] sendHELO:131 [0x178730] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=96000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 Jun 28 17:40:43 volumio volumio[4197]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jun 28 17:40:44 volumio volumio[4197]: error: MyVolumio Plugin failed to start in a timely fashion Jun 28 17:40:44 volumio volumio[4197]: info: BOOT COMPLETED Jun 28 17:40:44 volumio volumio[4197]: [Metrics] CommandRouter: 21s 985.75ms Jun 28 17:40:44 volumio volumio[4197]: info: CoreCommandRouter::volumiosetStartupVolume Jun 28 17:40:44 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:40:44 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:40:44 volumio volumio[4197]: info: CoreCommandRouter::Close All Modals sent Jun 28 17:40:44 volumio volumio[4197]: info: CoreCommandRouter::Close All Modals sent Jun 28 17:40:44 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Jun 28 17:40:45 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 28 17:40:45 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 28 17:40:45 volumio volumio[4197]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 28 17:40:47 volumio volumio[4197]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 17:40:47 volumio volumio[4197]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Jun 28 17:40:47 volumio volumio[4197]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jun 28 17:40:47 volumio volumio[4197]: errno: -3007, Jun 28 17:40:47 volumio volumio[4197]: code: 'ENOTFOUND', Jun 28 17:40:47 volumio volumio[4197]: syscall: 'getaddrinfo', Jun 28 17:40:47 volumio volumio[4197]: hostname: 'ws.audioscrobbler.com' Jun 28 17:40:47 volumio volumio[4197]: } Jun 28 17:40:47 volumio volumio[4197]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 17:40:47 volumio sudo[4465]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-06-28 17:39 Jun 28 17:40:47 volumio sudo[4465]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:40:47 volumio sudo[4465]: pam_unix(sudo:session): session closed for user root Jun 28 17:40:54 volumio volumio-remote-updater[779]: [2024-06-28 17:40:54] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] Jun 28 17:40:59 volumio volumio-remote-updater[779]: [2024-06-28 17:40:59] [connect] Successful connection Jun 28 17:41:01 volumio ntpd[1031]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Jun 28 17:41:12 volumio volumio-remote-updater[779]: [2024-06-28 17:41:12] [connect] Successful connection Jun 28 17:41:24 volumio ntpd[1031]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Jun 28 17:41:27 volumio volumio-remote-updater[779]: [2024-06-28 17:41:27] [connect] Successful connection Jun 28 17:41:33 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jun 28 17:41:33 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jun 28 17:41:33 volumio systemd[1]: Started dynamicswap service. Jun 28 17:41:33 volumio systemd[1]: dynamicswap.service: Succeeded. Jun 28 17:41:33 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jun 28 17:41:33 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11. Jun 28 17:41:33 volumio systemd[1]: Stopped Volumio Backend Module. Jun 28 17:41:33 volumio systemd[1]: Started Volumio Backend Module. Jun 28 17:41:33 volumio systemd[1]: Started dynamicswap service. Jun 28 17:41:33 volumio systemd[1]: dynamicswap.service: Succeeded. Jun 28 17:41:33 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:33 volumio volumio[4489]: info: ----- Volumio3 ---- Jun 28 17:41:33 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:33 volumio volumio[4489]: info: ----- System startup ---- Jun 28 17:41:33 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:33 volumio volumio[4489]: info: MYVOLUMIO Environment detected Jun 28 17:41:34 volumio volumio[4489]: info: Plugin folders cleanup Jun 28 17:41:34 volumio volumio[4489]: info: Scanning into folder /volumio/app/plugins/ Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category audio_interface Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category miscellanea Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category music_service Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category plugins.json Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category system_controller Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category user_interface Jun 28 17:41:34 volumio volumio[4489]: info: Scanning into folder /data/plugins/ Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category audio_interface Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category music_service Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category system_controller Jun 28 17:41:34 volumio volumio[4489]: info: Scanning category user_interface Jun 28 17:41:34 volumio volumio[4489]: info: Plugin folders cleanup completed Jun 28 17:41:34 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:34 volumio volumio[4489]: info: ----- Core plugins startup ---- Jun 28 17:41:34 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugins from folder /volumio/app/plugins/ Jun 28 17:41:34 volumio volumio[4489]: info: Adding plugin upnp to MyMusic Plugins Jun 28 17:41:34 volumio volumio[4489]: info: Adding plugin airplay_emulation to MyMusic Plugins Jun 28 17:41:34 volumio volumio[4489]: info: Adding plugin upnp_browser to MyMusic Plugins Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugins from folder /data/plugins/ Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "system"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "appearance"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "network"... Jun 28 17:41:34 volumio volumio[4489]: info: Refreshing Cached IP Addresses Jun 28 17:41:34 volumio sudo[4516]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "services"... Jun 28 17:41:34 volumio sudo[4516]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "alsa_controller"... Jun 28 17:41:34 volumio sudo[4516]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:34 volumio sudo[4518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 17:41:34 volumio sudo[4518]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:34 volumio sudo[4518]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:34 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "wizard"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "networkfs"... Jun 28 17:41:34 volumio volumio[4489]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 1 ,retrying in 5 seconds Jun 28 17:41:34 volumio volumio[4489]: info: Starting Udev Watcher for removable devices Jun 28 17:41:34 volumio volumio[4489]: info: Ignoring mount for partition: boot Jun 28 17:41:34 volumio volumio[4489]: info: Ignoring mount for partition: volumio Jun 28 17:41:34 volumio volumio[4489]: info: Ignoring mount for partition: volumio_data Jun 28 17:41:34 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "volumio_command_line_client"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "upnp"... Jun 28 17:41:34 volumio volumio[4489]: info: [1719621694270] Starting Upmpd Daemon Jun 28 17:41:34 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "my_music"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "mpd"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "upnp_browser"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "alarm-clock"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "airplay_emulation"... Jun 28 17:41:34 volumio volumio[4489]: info: Starting Shairport Sync Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "last_100"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "webradio"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "i2s_dacs"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "volumiodiscovery"... Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 17:41:34 volumio node[4489]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jun 28 17:41:34 volumio node[4489]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** For more information see Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:41:34 volumio volumio[4489]: *** WARNING *** For more information see Jun 28 17:41:34 volumio node[4489]: *** WARNING *** For more information see Jun 28 17:41:34 volumio node[4489]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jun 28 17:41:34 volumio node[4489]: *** WARNING *** Please fix your application to use the native API of Avahi! Jun 28 17:41:34 volumio node[4489]: *** WARNING *** For more information see Jun 28 17:41:34 volumio volumio[4489]: info: Applying required configuration parameters for plugin volumiodiscovery Jun 28 17:41:34 volumio volumio[4489]: info: Discovery: Started advertising with name: Volumio Jun 28 17:41:34 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jun 28 17:41:34 volumio volumio[4489]: info: Plugin squeezelite_mc is not enabled Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "outputs"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "albumart"... Jun 28 17:41:34 volumio volumio[4489]: info: Plugin example_plugin is not enabled Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "inputs"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "updater_comm"... Jun 28 17:41:34 volumio volumio[4489]: info: Plugin mpdemulation is not enabled Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "rest_api"... Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "websocket"... Jun 28 17:41:34 volumio volumio[4489]: info: Starting Socket.io Server version 2.3.0 Jun 28 17:41:34 volumio volumio[4489]: info: Plugin fusiondsp is not enabled Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "lms"... Jun 28 17:41:34 volumio volumio[4489]: Forking 3 albumart workers Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "pandora"... Jun 28 17:41:34 volumio volumio[4489]: Starting albumart workers Jun 28 17:41:34 volumio volumio[4489]: Starting albumart workers Jun 28 17:41:34 volumio volumio[4489]: Starting albumart workers Jun 28 17:41:34 volumio volumio[4489]: info: Applying required configuration parameters for plugin pandora Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "podcast"... Jun 28 17:41:34 volumio volumio[4489]: info: ControllerPodcast::constructor Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "backup_restore"... Jun 28 17:41:34 volumio volumio[4489]: info: Applying required configuration parameters for plugin backup_restore Jun 28 17:41:34 volumio volumio[4489]: info: Loading plugin "Systeminfo"... Jun 28 17:41:35 volumio volumio[4489]: info: Loading plugin "lastfm"... Jun 28 17:41:35 volumio volumio[4489]: info: Loading i18n strings for locale en Jun 28 17:41:35 volumio volumio[4489]: Updating browse sources language Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::initPlayerControls Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: Express server listening on port 3000 Jun 28 17:41:35 volumio volumio[4489]: [Metrics] WebUI: 1s 422.54ms Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::resetVolumioState Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::getcurrentVolume Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 17:41:35 volumio volumio[4489]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: Reloading queue from file Jun 28 17:41:35 volumio volumio[4489]: info: VolumeController:: Volume=100 Mute =false Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::pushState Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioPushState Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::updateTrackBlock Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getTrackBlock Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioRetrievevolume Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::setRepeat null single undefined Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::pushState Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioPushState Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::setRandom null Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::pushState Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioPushState Jun 28 17:41:35 volumio volumio[4489]: info: Setting Device type: Raspberry PI Jun 28 17:41:35 volumio volumio[4489]: info: Completed loading Core Plugins Jun 28 17:41:35 volumio volumio[4489]: info: Preparing to generate the ALSA configuration file Jun 28 17:41:35 volumio volumio[4489]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Jun 28 17:41:35 volumio volumio[4489]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c04170 Jun 28 17:41:35 volumio volumio[4489]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Jun 28 17:41:35 volumio volumio[4489]: info: VolumeController:: Volume=100 Mute =false Jun 28 17:41:35 volumio volumio[4489]: info: CoreStateMachine::pushState Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioPushState Jun 28 17:41:35 volumio volumio[4489]: info: Asound.conf file unchanged, so no further update is needed Jun 28 17:41:35 volumio volumio[4489]: info: Output device has changed, restarting MPD Jun 28 17:41:35 volumio sudo[4594]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 17:41:35 volumio sudo[4594]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio sudo[4594]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: info: Output device has changed, restarting Shairport Sync Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio sudo[4597]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 17:41:35 volumio sudo[4597]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio systemd[1]: Stopping Music Player Daemon... Jun 28 17:41:35 volumio volumio[4489]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:41:35 volumio volumio[4489]: info: ___________ START PLUGINS ___________ Jun 28 17:41:35 volumio volumio[4489]: info: ControllerMpd::onStart: Initializing MPD Jun 28 17:41:35 volumio volumio[4489]: info: Creating MPD Configuration file Jun 28 17:41:35 volumio sudo[4603]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 28 17:41:35 volumio sudo[4603]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio sudo[4603]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695331] CoreMusicLibrary::Adding element Media Servers Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio sudo[4606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 28 17:41:35 volumio sudo[4606]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio systemd[1]: mpd.service: Succeeded. Jun 28 17:41:35 volumio systemd[1]: Stopped Music Player Daemon. Jun 28 17:41:35 volumio volumio[4489]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695366] CoreMusicLibrary::Adding element Last_100 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695367] CoreMusicLibrary::Adding element Webradio Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:41:35 volumio volumio[4489]: info: Initializing BBC Radios Jun 28 17:41:35 volumio systemd[1]: Starting Music Player Daemon... Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695397] CoreMusicLibrary::Adding element Pandora Radio Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source Pandora Radio Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695398] ControllerPandora::initializeMQTT Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695398] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Jun 28 17:41:35 volumio sudo[4627]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Jun 28 17:41:35 volumio sudo[4627]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695401] CoreMusicLibrary::Adding element Podcast Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source Pandora Radio Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source Podcast Jun 28 17:41:35 volumio sudo[4609]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 28 17:41:35 volumio sudo[4609]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695403] CoreMusicLibrary::Adding element LastFM Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source Pandora Radio Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source Podcast Jun 28 17:41:35 volumio sudo[4609]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: Cannot find translation for source LastFM Jun 28 17:41:35 volumio volumio[4489]: info: [LastFM] scrobbler initiated! Jun 28 17:41:35 volumio volumio[4489]: info: [LastFM] extended logging: false Jun 28 17:41:35 volumio volumio[4489]: info: [LastFM] try scrobble stream/radio plays: true Jun 28 17:41:35 volumio volumio[4489]: info: [LastFM] Left init routine Jun 28 17:41:35 volumio volumio[4489]: info: [LastFM] Socket already connected: true Jun 28 17:41:35 volumio volumio[4489]: info: Volumio Calling Home Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.409] Stop:1575 stopping squeezelite devices ... Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.409] slimproto_close:957 [0x178730] slimproto stop for Volumio-UPnP/AV Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.409] sighandler:1619 Please wait for clean exit! Jun 28 17:41:35 volumio systemd[1]: Stopping Logitech Media Server... Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695428] ControllerPandora::initialSetup Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695429] ControllerPandora::PandoraHandler::init Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695429] ControllerPandora::PandoraHandler::loadErrorCodes Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695432] [Pandora] PandoraHandler::setMaxStationTracks: 16 Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695433] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695433] ControllerPandora::flushPandora Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::getQueue Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::clearAddPlayQueue Jun 28 17:41:35 volumio volumio[4489]: info: CorePlayQueue::saveQueue Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::serviceClearAddPlayTracks Jun 28 17:41:35 volumio volumio[4489]: error: WARNING: No clearAddPlayTracks method for service webradio Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::volumioPushQueue Jun 28 17:41:35 volumio volumio[4489]: info: [1719621695435] ControllerPandora::validateAndSetAccountOptions Jun 28 17:41:35 volumio volumio[4489]: error: [1719621695435] [Pandora] validateAndSetAccountOptions: Need email address and password. See plugin settings. Jun 28 17:41:35 volumio volumio[4489]: info: MPD Permissions set Jun 28 17:41:35 volumio volumio[4489]: info: MPD Permissions set Jun 28 17:41:35 volumio volumio[4489]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:35 volumio volumio[4489]: info: Starting Shairport Sync Jun 28 17:41:35 volumio volumio[4489]: info: Starting Shairport Sync Jun 28 17:41:35 volumio sudo[4643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:41:35 volumio sudo[4643]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio volumio[4489]: info: Starting Shairport Sync Jun 28 17:41:35 volumio sudo[4646]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:41:35 volumio sudo[4646]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 17:41:35 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 28 17:41:35 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 17:41:35 volumio sudo[4649]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 28 17:41:35 volumio sudo[4649]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:35 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 17:41:35 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 28 17:41:35 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Jun 28 17:41:35 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 28 17:41:35 volumio sudo[4643]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 28 17:41:35 volumio volumio[4489]: info: Shairport-Sync Started Jun 28 17:41:35 volumio volumio[4489]: Error adding Membership: Error: addMembership EINVAL Jun 28 17:41:35 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.596] Stop:1579 terminate update thread ... Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.596] Stop:1584 terminate main thread ... Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.596] Stop:1587 stopping UPnP devices ... Jun 28 17:41:35 volumio sudo[4646]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio squeezeboxserver[4367]: [17:41:35.598] sighandler:1633 all done - exit through signal Jun 28 17:41:35 volumio sudo[4649]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: info: Shairport-Sync Started Jun 28 17:41:35 volumio volumio[4489]: info: Shairport-Sync Started Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:25.9319] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.4069] Plugins::Live365::Plugin::__ANON__ (174) Failed to get initial page from Live365.com - error: Couldn't resolve IP address for: live365.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.4973] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting https://www.mysqueezebox.com/api/sounds/v1/opml Jun 28 17:41:35 volumio squeezeboxserver[4367]: Couldn't resolve IP address for: www.mysqueezebox.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.4976] Slim::Plugin::Sounds::Plugin::_gotSoundsError (82) Error: Unable to cache Sounds & Effects menu from SN: Couldn't resolve IP address for: www.mysqueezebox.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.5577] Slim::Networking::Repositories::__ANON__ (147) Failed to fetch https://github.com/LMS-Community/lms-plugin-repository/raw/master/extensions.xml: Couldn't resolve IP address for: github.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.5883] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:41:35 volumio squeezeboxserver[4367]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:35.5885] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:39.1186] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:39.1414] Slim::Plugin::UPnP::Events::error (326) Subscribe/unsubscribe error: 412 Precondition Failed Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:55.0081] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:41:35 volumio squeezeboxserver[4367]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:40:55.0083] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:41:25.0073] Slim::Formats::XML::gotErrorViaHTTP (343) Error: getting http://opml.radiotime.com/Index.aspx?partnerId=16 Jun 28 17:41:35 volumio squeezeboxserver[4367]: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio squeezeboxserver[4367]: [24-06-28 17:41:25.0075] Slim::Plugin::InternetRadio::Plugin::_gotRadioError (71) Unable to retrieve radio directory from SN: Couldn't resolve IP address for: opml.radiotime.com Jun 28 17:41:35 volumio systemd[1]: logitechmediaserver.service: Succeeded. Jun 28 17:41:35 volumio systemd[1]: Stopped Logitech Media Server. Jun 28 17:41:35 volumio mpd[4630]: Jun 28 17:41 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 28 17:41:35 volumio systemd[1]: Started Logitech Media Server. Jun 28 17:41:35 volumio sudo[4627]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: info: logitechmediaserver started Jun 28 17:41:35 volumio systemd[1]: Started Music Player Daemon. Jun 28 17:41:35 volumio sudo[4597]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio sudo[4606]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:35 volumio volumio[4489]: info: Completed starting Core Plugins Jun 28 17:41:35 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:35 volumio volumio[4489]: info: ----- MyVolumio plugins startup ---- Jun 28 17:41:35 volumio volumio[4489]: info: ------------------------------------------- Jun 28 17:41:35 volumio volumio[4489]: info: [MyVolumio PluginManager] Fetching plans data.... Jun 28 17:41:35 volumio volumio[4489]: error: MPD error: The expression evaluated to a falsy value: Jun 28 17:41:35 volumio volumio[4489]: assert.ok(self.idling) Jun 28 17:41:35 volumio volumio[4489]: error: The expression evaluated to a falsy value: Jun 28 17:41:35 volumio volumio[4489]: assert.ok(self.idling) Jun 28 17:41:35 volumio volumio[4489]: info: MPD running with PID4630 Jun 28 17:41:35 volumio volumio[4489]: ,establishing connection Jun 28 17:41:35 volumio volumio[4489]: error: updateQueue error: null Jun 28 17:41:35 volumio volumio[4489]: error: updateQueue error: null Jun 28 17:41:36 volumio squeezeboxserver[4658]: [24-06-28 17:41:36.2250] main::init (377) Starting Logitech Media Server (v8.3.0, 1667251155, Fri 04 Nov 2022 09:17:53 AM CET) perl 5.028001 - arm-linux-gnueabihf-thread-multi-64int Jun 28 17:41:36 volumio squeezeboxserver[4658]: [17:41:36.608] main:1831 Starting squeeze2upnp version: v3.3.9 (Apr 5 2024 @ 22:09:49) Jun 28 17:41:36 volumio squeezeboxserver[4658]: [17:41:36.662] Start:1530 Binding to iface 192.168.88.24:49154 [eth0] (http port 0) Jun 28 17:41:36 volumio squeezeboxserver[4658]: [17:41:36.662] Start:1566 UPnP search for urn:schemas-upnp-org:device:MediaRenderer:1 Jun 28 17:41:36 volumio squeezeboxserver[4658]: [17:41:36.863] Start:1566 UPnP search for urn:schemas-upnp-org:device:MediaRenderer:2 Jun 28 17:41:37 volumio volumio[4489]: info: CoreCommandRouter::volumioGetState Jun 28 17:41:37 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:37 volumio volumio[4489]: info: Listing playlists Jun 28 17:41:37 volumio volumio[4489]: info: Listing playlists Jun 28 17:41:39 volumio volumio[4489]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 2 ,retrying in 5 seconds Jun 28 17:41:41 volumio volumio[4489]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jun 28 17:41:42 volumio volumio-remote-updater[779]: [2024-06-28 17:41:42] [connect] Successful connection Jun 28 17:41:42 volumio volumio-remote-updater[779]: [2024-06-28 17:41:42] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1719621702 101 Jun 28 17:41:42 volumio volumio[4489]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Jun 28 17:41:44 volumio volumio[4489]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 3 ,retrying in 5 seconds Jun 28 17:41:44 volumio sudo[4722]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jun 28 17:41:44 volumio sudo[4722]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:44 volumio sudo[4722]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:44 volumio sudo[4725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jun 28 17:41:44 volumio sudo[4725]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:44 volumio sudo[4725]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:47 volumio ntpd[1031]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Jun 28 17:41:47 volumio sudo[4728]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jun 28 17:41:47 volumio sudo[4728]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 28 17:41:47 volumio sudo[4728]: pam_unix(sudo:session): session closed for user root Jun 28 17:41:49 volumio volumio[4489]: Cannot compose Albumart path Jun 28 17:41:49 volumio volumio[4489]: info: Upmpdcli Daemon Started Jun 28 17:41:49 volumio volumio[4489]: info: CoreCommandRouter::volumioGetState Jun 28 17:41:49 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:49 volumio volumio[4489]: info: Cannot mount NAS MyCloud_Music at system boot, trial number 4 ,retrying in 5 seconds Jun 28 17:41:54 volumio volumio[4489]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jun 28 17:41:55 volumio volumio[4489]: error: MyVolumio Plugin failed to start in a timely fashion Jun 28 17:41:55 volumio volumio[4489]: info: BOOT COMPLETED Jun 28 17:41:55 volumio volumio[4489]: [Metrics] CommandRouter: 22s 8.70ms Jun 28 17:41:55 volumio volumio[4489]: info: CoreCommandRouter::volumiosetStartupVolume Jun 28 17:41:55 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 28 17:41:55 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 28 17:41:55 volumio volumio[4489]: info: CoreCommandRouter::Close All Modals sent Jun 28 17:41:55 volumio volumio[4489]: info: CoreCommandRouter::Close All Modals sent Jun 28 17:41:55 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Jun 28 17:41:56 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 28 17:41:56 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 28 17:41:56 volumio volumio[4489]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.294] AddMRDevice:1455 [0x1f5290]: adding renderer (Volumio-UPnP/AV) 192.168.88.24 with mac BBBB-F107F44E Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.295] MasterHandler:1075 [0x1f5290]: subscribe success Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.297] slimproto:885 squeezelite [0x178730] <=> player [0x1f5290] Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.297] slimproto:886 [0x178730] connecting to 192.168.88.24:3483 Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.297] slimproto:916 [0x178730] connected Jun 28 17:41:57 volumio squeezeboxserver[4658]: [17:41:57.297] sendHELO:131 [0x178730] cap: CanHTTPS=1,Model=squeezelite,ModelName=UPnPBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=96000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3 Jun 28 17:41:57 volumio volumio[4489]: info: CoreCommandRouter::volumioGetState Jun 28 17:41:57 volumio volumio[4489]: info: CorePlayQueue::getTrack 0 Jun 28 17:41:57 volumio volumio[4489]: info: Listing playlists Jun 28 17:41:57 volumio volumio[4489]: info: Listing playlists Jun 28 17:41:58 volumio volumio[4489]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 17:41:58 volumio volumio[4489]: Error: getaddrinfo ENOTFOUND ws.audioscrobbler.com Jun 28 17:41:58 volumio volumio[4489]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Jun 28 17:41:58 volumio volumio[4489]: errno: -3007, Jun 28 17:41:58 volumio volumio[4489]: code: 'ENOTFOUND', Jun 28 17:41:58 volumio volumio[4489]: syscall: 'getaddrinfo', Jun 28 17:41:58 volumio volumio[4489]: hostname: 'ws.audioscrobbler.com' Jun 28 17:41:58 volumio volumio[4489]: } Jun 28 17:41:58 volumio volumio[4489]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 28 17:41:58 volumio sudo[4751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-06-28 17:40 Jun 28 17:41:58 volumio sudo[4751]: 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="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 08:41:12 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="8e78a6e3f56f1bcbbd1760812129a8e9"