-- Logs begin at Mon 2024-07-22 11:22:29 MDT, end at Sat 2024-08-17 12:13:55 MDT. -- Aug 17 12:12:03 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Aug 17 12:12:10 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Aug 17 12:12:10 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Aug 17 12:12:10 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 17 12:12:10 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:10 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:12:16 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule Aug 17 12:12:16 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 12:12:16 volumio systemd[1]: systemd-timedated.service: Succeeded. Aug 17 12:12:16 volumio volumio-remote-updater[664]: No test mode Aug 17 12:12:16 volumio volumio-remote-updater[664]: No alpha test mode Aug 17 12:12:16 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Aug 17 12:12:16 volumio volumio[908]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Aug 17 12:12:16 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Aug 17 12:12:28 volumio volumio[908]: info: Preparing to save Alsa Options, stopping services first Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:12:28 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::volumioPause Aug 17 12:12:28 volumio volumio[908]: info: CoreStateMachine::pause Aug 17 12:12:28 volumio volumio[908]: info: Saving Audio Output to: {"i2s":true,"i2sid":{"value":"pecan-plus-dac","label":"Orchard Audio PecanPi+ DAC"},"output_device":{"value":1,"label":"Orchard Audio PecanPi+ DAC"},"disallowPush":true} Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:28 volumio volumio[908]: info: Enabling I2S DAC: Orchard Audio PecanPi+ DAC Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Aug 17 12:12:28 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:28 volumio sudo[1935]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Aug 17 12:12:28 volumio sudo[1935]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio sudo[1935]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: info: No Overlays Loaded Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio sudo[1938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dacplusdsp Aug 17 12:12:29 volumio sudo[1938]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status Aug 17 12:12:29 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Aug 17 12:12:29 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Aug 17 12:12:29 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Aug 17 12:12:29 volumio volumio[908]: warn: Unable to locate the device Orchard Audio PecanPi+ DAC a reboot may be required. Aug 17 12:12:29 volumio sudo[1938]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio systemd-udevd[1947]: Process '/usr/sbin/alsactl -E HOME=/run/alsa restore 2' failed with exit code 99. Aug 17 12:12:29 volumio volumio[908]: info: Device 2 does not have any Mixer Control Available Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 17 12:12:29 volumio volumio[908]: info: Updating Volume Controller Parameters: Device: 2 Name: Orchard Audio PecanPi+ DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 17 12:12:29 volumio volumio[908]: info: Disabling external Volume Control Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: Preparing to generate the ALSA configuration file Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 17 12:12:29 volumio sudo[1964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 17 12:12:29 volumio sudo[1964]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio volumio[908]: info: Aug 17 12:12:29 volumio volumio[908]: ---------------------------- MPD announces state update: mixer Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::getState Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::sendMpdCommand status Aug 17 12:12:29 volumio volumio[908]: info: Aug 17 12:12:29 volumio volumio[908]: ---------------------------- MPD announces state update: mixer Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::getState Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::sendMpdCommand status Aug 17 12:12:29 volumio volumio[908]: info: Aug 17 12:12:29 volumio volumio[908]: ---------------------------- MPD announces state update: mixer Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::getState Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::sendMpdCommand status Aug 17 12:12:29 volumio sudo[1967]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 17 12:12:29 volumio volumio[908]: info: I2S Param [object Object] successfully enabled Aug 17 12:12:29 volumio sudo[1967]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio volumio[908]: info: sendMpdCommand status took 10 milliseconds Aug 17 12:12:29 volumio volumio[908]: info: sendMpdCommand status took 9 milliseconds Aug 17 12:12:29 volumio sudo[1967]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: info: sendMpdCommand status took 9 milliseconds Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::parseState Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::parseState Aug 17 12:12:29 volumio volumio[908]: verbose: ControllerMpd::parseState Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::pushState Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::servicePushState Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 17 12:12:29 volumio volumio[908]: verbose: CURRENT POSITION 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState stateService stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState currentStatus stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: No code Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::pushState Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::servicePushState Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 17 12:12:29 volumio volumio[908]: verbose: CURRENT POSITION 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState stateService stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState currentStatus stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: No code Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: ControllerMpd::pushState Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::servicePushState Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Aug 17 12:12:29 volumio volumio[908]: verbose: CURRENT POSITION 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState stateService stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::syncState currentStatus stop Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: No code Aug 17 12:12:29 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:29 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:29 volumio volumio[908]: info: ------------------------------ 67ms Aug 17 12:12:29 volumio volumio[908]: info: ------------------------------ 65ms Aug 17 12:12:29 volumio volumio[908]: info: ------------------------------ 64ms Aug 17 12:12:29 volumio volumio[908]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 17 12:12:29 volumio volumio[908]: wlan0 Interface doesn't support scanning : Device or resource busy Aug 17 12:12:29 volumio volumio[908]: info: Cannot use regular scanning, forcing with ap-force Aug 17 12:12:29 volumio sudo[1970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 17 12:12:29 volumio sudo[1970]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio sudo[1970]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: command failed: Device or resource busy (-16) Aug 17 12:12:29 volumio volumio[908]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Aug 17 12:12:29 volumio volumio[908]: command failed: Device or resource busy (-16) Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:12:29 volumio volumio[908]: info: Getting Alsa Cards List without I2S DAC Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 17 12:12:29 volumio volumio[908]: info: Asound.conf file written Aug 17 12:12:29 volumio sudo[1981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Aug 17 12:12:29 volumio sudo[1981]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio sudo[1981]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: No state is present for card b1 Aug 17 12:12:29 volumio volumio[908]: /usr/share/alsa/init/bcm2835:14: control element not found Aug 17 12:12:29 volumio volumio[908]: No state is present for card b1 Aug 17 12:12:29 volumio volumio[908]: No state is present for card Headphones Aug 17 12:12:29 volumio volumio[908]: /usr/share/alsa/init/bcm2835:20: control element not found Aug 17 12:12:29 volumio volumio[908]: No state is present for card Headphones Aug 17 12:12:29 volumio volumio[908]: No state is present for card sndrpihifiberry Aug 17 12:12:29 volumio volumio[908]: Found hardware: "RPi-simple" "" "" "" "" Aug 17 12:12:29 volumio volumio[908]: Hardware is initialized using a generic method Aug 17 12:12:29 volumio volumio[908]: No state is present for card sndrpihifiberry Aug 17 12:12:29 volumio volumio[908]: info: Output device has changed, restarting MPD Aug 17 12:12:29 volumio sudo[1986]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 17 12:12:29 volumio sudo[1986]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio volumio[908]: info: Output device has changed, restarting Shairport Sync Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio sudo[1986]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio sudo[1989]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 17 12:12:29 volumio sudo[1989]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio systemd[1]: Stopping Music Player Daemon... Aug 17 12:12:29 volumio volumio[908]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 17 12:12:29 volumio volumio[908]: info: Output device has changed, restarting MPD Aug 17 12:12:29 volumio volumio[908]: info: Output device has changed, restarting Shairport Sync Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio sudo[1995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 17 12:12:29 volumio sudo[1995]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio sudo[1995]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio sudo[1997]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 17 12:12:29 volumio sudo[1997]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio systemd[1]: mpd.service: Succeeded. Aug 17 12:12:29 volumio systemd[1]: Stopped Music Player Daemon. Aug 17 12:12:29 volumio volumio[908]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 17 12:12:29 volumio volumio[908]: info: MPD Permissions set Aug 17 12:12:29 volumio volumio[908]: info: MPD Permissions set Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio systemd[1]: Starting Music Player Daemon... Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:12:29 volumio volumio[908]: info: Starting Shairport Sync Aug 17 12:12:29 volumio volumio[908]: info: Starting Shairport Sync Aug 17 12:12:29 volumio sudo[2013]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 17 12:12:29 volumio sudo[2013]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio sudo[2003]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 17 12:12:29 volumio sudo[2003]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 17 12:12:29 volumio sudo[2003]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 17 12:12:29 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 17 12:12:29 volumio sudo[2015]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 17 12:12:29 volumio sudo[2015]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:29 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 17 12:12:29 volumio sudo[2013]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:29 volumio volumio[908]: info: Shairport-Sync Started Aug 17 12:12:30 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 17 12:12:30 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 17 12:12:30 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 17 12:12:30 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 17 12:12:30 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 17 12:12:30 volumio sudo[2015]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:30 volumio volumio[908]: info: Shairport-Sync Started Aug 17 12:12:30 volumio mpd[2018]: Aug 17 12:12 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 17 12:12:30 volumio systemd[1]: Started Music Player Daemon. Aug 17 12:12:30 volumio sudo[1997]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:30 volumio sudo[1989]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:30 volumio volumio[908]: error: MPD error: The expression evaluated to a falsy value: Aug 17 12:12:30 volumio volumio[908]: assert.ok(self.idling) Aug 17 12:12:30 volumio volumio[908]: error: The expression evaluated to a falsy value: Aug 17 12:12:30 volumio volumio[908]: assert.ok(self.idling) Aug 17 12:12:30 volumio volumio[908]: error: updateQueue error: null Aug 17 12:12:33 volumio volumio[908]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Aug 17 12:12:33 volumio volumio[908]: info: CoreStateMachine::getcurrentVolume Aug 17 12:12:33 volumio volumio[908]: info: CoreCommandRouter::volumioRetrievevolume Aug 17 12:12:33 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:12:33 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:33 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:12:33 volumio sudo[1964]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:42 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , connectWirelessNetwork Aug 17 12:12:42 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWiredInfo Aug 17 12:12:42 volumio sudo[2028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 17 12:12:42 volumio sudo[2028]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:42 volumio sudo[2028]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:42 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings Aug 17 12:12:42 volumio volumio[908]: info: Saving new wireless network Aug 17 12:12:42 volumio sudo[2031]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf Aug 17 12:12:42 volumio sudo[2031]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:42 volumio sudo[2031]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:42 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart Aug 17 12:12:42 volumio volumio[908]: info: Discovery: Restarting Advertising due to device name change Aug 17 12:12:42 volumio sudo[2034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service Aug 17 12:12:42 volumio sudo[2034]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:42 volumio systemd[1]: Starting Wireless Services... Aug 17 12:12:42 volumio wireless.js[2036]: Cleaning previous... Aug 17 12:12:42 volumio systemd[1]: Stopping Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Aug 17 12:12:43 volumio systemd[1]: hostapd.service: Succeeded. Aug 17 12:12:43 volumio systemd[1]: Stopped Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Aug 17 12:12:43 volumio sudo[2051]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 17 12:12:43 volumio sudo[2051]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:43 volumio avahi-daemon[662]: Withdrawing address record for 192.168.211.1 on wlan0. Aug 17 12:12:43 volumio avahi-daemon[662]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Aug 17 12:12:43 volumio avahi-daemon[662]: Interface wlan0.IPv4 no longer relevant for mDNS. Aug 17 12:12:43 volumio volumio[908]: info: Discovery: A device disappeared from network Aug 17 12:12:43 volumio sudo[2051]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:43 volumio volumio[908]: info: Discovery: Device volumio disappeared from network Aug 17 12:12:43 volumio volumio[908]: info: Discovery: A device disappeared from network Aug 17 12:12:43 volumio sudo[2053]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 17 12:12:43 volumio sudo[2053]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:44 volumio sudo[2053]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:44 volumio wireless.js[2036]: Stopped aP Aug 17 12:12:44 volumio sudo[2060]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 17 12:12:44 volumio sudo[2060]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:44 volumio sudo[2060]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:44 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 17 12:12:44 volumio sudo[2062]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get Aug 17 12:12:44 volumio sudo[2062]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:44 volumio sudo[2062]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:44 volumio sudo[2069]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 17 12:12:44 volumio sudo[2069]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:44 volumio sudo[2069]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:44 volumio sudo[2071]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan Aug 17 12:12:44 volumio sudo[2071]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:45 volumio ntpd[805]: Deleting interface #5 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=207 secs Aug 17 12:12:46 volumio sudo[2071]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:46 volumio wireless.js[2036]: SETTING APPROPRIATE REG DOMAIN: US Aug 17 12:12:47 volumio sudo[2076]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up Aug 17 12:12:47 volumio sudo[2076]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:47 volumio sudo[2076]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:47 volumio sudo[2078]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set US Aug 17 12:12:47 volumio sudo[2078]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:47 volumio sudo[2078]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:47 volumio wireless.js[2036]: SUCCESSFULLY SET NEW REGDOMAIN: US Aug 17 12:12:47 volumio wireless.js[2036]: Start wireless flow Aug 17 12:12:47 volumio wireless.js[2036]: Stopped hotspot (if there).. Aug 17 12:12:47 volumio sudo[2083]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 17 12:12:47 volumio sudo[2083]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:47 volumio sudo[2083]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:47 volumio sudo[2085]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 17 12:12:47 volumio sudo[2085]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:47 volumio volumio[908]: info: Discovery: Started advertising with name: Volumio Aug 17 12:12:47 volumio sudo[2085]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:47 volumio wireless.js[2036]: DHCP IP Aug 17 12:12:47 volumio wireless.js[2036]: Start ap Aug 17 12:12:47 volumio wpa_supplicant[2088]: Successfully initialized wpa_supplicant Aug 17 12:12:47 volumio sudo[2089]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd Aug 17 12:12:47 volumio sudo[2089]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:47 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 17 12:12:47 volumio dhcpcd[2090]: dev: loaded udev Aug 17 12:12:47 volumio dhcpcd-run-hooks[2099]: wlan0: starting wpa_supplicant Aug 17 12:12:47 volumio dhcpcd-run-hooks[2104]: wlan0: failed to start wpa_supplicant Aug 17 12:12:47 volumio dhcpcd-run-hooks[2105]: wlan0: Successfully initialized wpa_supplicant nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Match already configured nl80211: kernel reports: Ma Aug 17 12:12:47 volumio dhcpcd[2090]: wlan0: connected to Access Point `' Aug 17 12:12:47 volumio dhcpcd[2090]: DUID 00:01:00:01:2e:31:51:de:dc:a6:32:fd:76:b0 Aug 17 12:12:47 volumio dhcpcd[2090]: eth0: IAID 32:fd:76:b0 Aug 17 12:12:47 volumio dhcpcd[2090]: eth0: adding address fe80::d5cc:cf1d:77c3:7dc6 Aug 17 12:12:47 volumio dhcpcd[2090]: ipv6_addaddr1: Permission denied Aug 17 12:12:47 volumio dhcpcd[2090]: wlan0: waiting for carrier Aug 17 12:12:48 volumio volumio[908]: info: Discovery: adding 83650003-a6b7-4fa1-8cc1-bc549b10a0f4 Aug 17 12:12:48 volumio volumio[908]: info: Discovery: Found device Volumio Aug 17 12:12:48 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:12:48 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:12:48 volumio dhcpcd[2090]: eth0: soliciting a DHCP lease Aug 17 12:12:48 volumio wireless.js[2036]: trying... Aug 17 12:12:48 volumio sudo[2124]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:48 volumio sudo[2124]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:48 volumio sudo[2124]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:48 volumio dhcpcd[2090]: eth0: offered 192.168.68.71 from 192.168.68.1 Aug 17 12:12:48 volumio dhcpcd[2090]: eth0: leased 192.168.68.71 for 7200 seconds Aug 17 12:12:48 volumio dhcpcd[2090]: eth0: adding route to 192.168.68.0/22 Aug 17 12:12:48 volumio dhcpcd[2090]: eth0: adding default route via 192.168.68.1 Aug 17 12:12:48 volumio dhcpcd[2090]: forked to background, child pid 2146 Aug 17 12:12:48 volumio sudo[2089]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:48 volumio dhcpcd[2146]: eth0: soliciting an IPv6 router Aug 17 12:12:49 volumio wireless.js[2036]: trying... Aug 17 12:12:49 volumio sudo[2148]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:49 volumio sudo[2148]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:49 volumio sudo[2148]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:50 volumio wpa_supplicant[2103]: wlan0: Trying to associate with SSID 'TheLodge' Aug 17 12:12:50 volumio wireless.js[2036]: trying... Aug 17 12:12:50 volumio sudo[2151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:50 volumio sudo[2151]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:50 volumio sudo[2151]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:51 volumio wireless.js[2036]: trying... Aug 17 12:12:51 volumio sudo[2154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:51 volumio sudo[2154]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:51 volumio sudo[2154]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:52 volumio wireless.js[2036]: trying... Aug 17 12:12:52 volumio sudo[2157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:52 volumio sudo[2157]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:52 volumio sudo[2157]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:53 volumio wireless.js[2036]: trying... Aug 17 12:12:53 volumio sudo[2160]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:53 volumio sudo[2160]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:53 volumio sudo[2160]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:54 volumio wireless.js[2036]: trying... Aug 17 12:12:54 volumio sudo[2164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:54 volumio sudo[2164]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:54 volumio sudo[2164]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:55 volumio wireless.js[2036]: trying... Aug 17 12:12:55 volumio sudo[2190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:55 volumio sudo[2190]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:55 volumio sudo[2190]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:56 volumio wireless.js[2036]: trying... Aug 17 12:12:56 volumio sudo[2211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:56 volumio sudo[2211]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:56 volumio sudo[2211]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:57 volumio wireless.js[2036]: trying... Aug 17 12:12:57 volumio sudo[2214]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:57 volumio sudo[2214]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:57 volumio sudo[2214]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:58 volumio wireless.js[2036]: trying... Aug 17 12:12:58 volumio sudo[2217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:58 volumio sudo[2217]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:58 volumio sudo[2217]: pam_unix(sudo:session): session closed for user root Aug 17 12:12:59 volumio wireless.js[2036]: trying... Aug 17 12:12:59 volumio sudo[2220]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:12:59 volumio sudo[2220]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:12:59 volumio sudo[2220]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:00 volumio wpa_supplicant[2103]: wlan0: Authentication with 48:22:54:a2:ef:a3 timed out. Aug 17 12:13:00 volumio wpa_supplicant[2103]: wlan0: CTRL-EVENT-DISCONNECTED bssid=48:22:54:a2:ef:a3 reason=3 locally_generated=1 Aug 17 12:13:00 volumio wpa_supplicant[2103]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD Aug 17 12:13:00 volumio wpa_supplicant[2103]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US Aug 17 12:13:00 volumio wireless.js[2036]: trying... Aug 17 12:13:00 volumio sudo[2223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:00 volumio sudo[2223]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:00 volumio sudo[2223]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:01 volumio wireless.js[2036]: trying... Aug 17 12:13:01 volumio sudo[2226]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:01 volumio sudo[2226]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:01 volumio sudo[2226]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:02 volumio wireless.js[2036]: trying... Aug 17 12:13:02 volumio sudo[2229]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:02 volumio sudo[2229]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:02 volumio sudo[2229]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:03 volumio wpa_supplicant[2103]: wlan0: Trying to associate with SSID 'TheLodge' Aug 17 12:13:03 volumio wireless.js[2036]: trying... Aug 17 12:13:03 volumio sudo[2232]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:03 volumio sudo[2232]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:03 volumio sudo[2232]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:04 volumio wireless.js[2036]: trying... Aug 17 12:13:04 volumio sudo[2235]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:04 volumio sudo[2235]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:04 volumio sudo[2235]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:04 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices Aug 17 12:13:04 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 17 12:13:04 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:04 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:13:05 volumio wireless.js[2036]: trying... Aug 17 12:13:05 volumio sudo[2240]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:05 volumio sudo[2240]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:05 volumio sudo[2240]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:06 volumio wireless.js[2036]: trying... Aug 17 12:13:06 volumio sudo[2243]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:06 volumio sudo[2243]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:06 volumio sudo[2243]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:07 volumio wireless.js[2036]: trying... Aug 17 12:13:07 volumio sudo[2246]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r Aug 17 12:13:07 volumio sudo[2246]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:07 volumio sudo[2246]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Aug 17 12:13:08 volumio volumio[908]: info: Preparing to save Alsa Options, stopping services first Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:08 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::volumioPause Aug 17 12:13:08 volumio volumio[908]: info: CoreStateMachine::pause Aug 17 12:13:08 volumio volumio[908]: info: Saving Audio Output to: {"i2s":true,"i2sid":{"label":"Orchard Audio PecanPi+ DAC"},"output_device":{"value":1,"label":"Orchard Audio PecanPi+ DAC"},"disallowPush":true} Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: Device 2 does not have any Mixer Control Available Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::volumioUpdateVolumeSettings Aug 17 12:13:08 volumio volumio[908]: info: Updating Volume Controller Parameters: Device: 2 Name: Orchard Audio PecanPi+ DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Aug 17 12:13:08 volumio volumio[908]: info: Disabling external Volume Control Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:08 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:13:08 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:13:08 volumio volumio[908]: info: Preparing to generate the ALSA configuration file Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Aug 17 12:13:08 volumio sudo[2257]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 17 12:13:08 volumio sudo[2257]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio sudo[2257]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Aug 17 12:13:08 volumio volumio[908]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 17 12:13:08 volumio volumio[908]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Aug 17 12:13:08 volumio volumio[908]: info: Cannot use regular scanning, forcing with ap-force Aug 17 12:13:08 volumio sudo[2260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Aug 17 12:13:08 volumio sudo[2260]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio sudo[2260]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Aug 17 12:13:08 volumio sudo[2263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 17 12:13:08 volumio sudo[2263]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio sudo[2263]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Aug 17 12:13:08 volumio volumio[908]: command failed: Resource temporarily unavailable (-11) Aug 17 12:13:08 volumio volumio[908]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Aug 17 12:13:08 volumio volumio[908]: command failed: Resource temporarily unavailable (-11) Aug 17 12:13:08 volumio volumio[908]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Aug 17 12:13:08 volumio volumio[908]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Aug 17 12:13:08 volumio volumio[908]: info: Cannot use regular scanning, forcing with ap-force Aug 17 12:13:08 volumio wireless.js[2036]: Overtime, starting plan B Aug 17 12:13:08 volumio wireless.js[2036]: STARTING HOTSPOT Aug 17 12:13:08 volumio sudo[2266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Aug 17 12:13:08 volumio sudo[2266]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (67) Aug 17 12:13:08 volumio sudo[2266]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio volumio[908]: command failed: Resource temporarily unavailable (-11) Aug 17 12:13:08 volumio volumio[908]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Aug 17 12:13:08 volumio volumio[908]: command failed: Resource temporarily unavailable (-11) Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: Failed to set IPv4 unicast in multicast filter Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: Failed to set IPv4 unicast in multicast filter Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 17 12:13:08 volumio volumio[908]: info: Getting Alsa Cards List without I2S DAC Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio wpa_supplicant[2103]: p2p-dev-wlan0: CTRL-EVENT-TERMINATING Aug 17 12:13:08 volumio wpa_supplicant[2103]: wlan0: CTRL-EVENT-DISCONNECTED bssid=5a:22:54:4f:19:a6 reason=3 locally_generated=1 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Aug 17 12:13:08 volumio volumio[908]: info: Asound.conf file unchanged, so no further update is needed Aug 17 12:13:08 volumio volumio[908]: info: Output device has changed, restarting MPD Aug 17 12:13:08 volumio sudo[2281]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 17 12:13:08 volumio sudo[2281]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio volumio[908]: info: Output device has changed, restarting Shairport Sync Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio sudo[2281]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio sudo[2284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 17 12:13:08 volumio sudo[2284]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio systemd[1]: Stopping Music Player Daemon... Aug 17 12:13:08 volumio volumio[908]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 17 12:13:08 volumio volumio[908]: info: MPD Permissions set Aug 17 12:13:08 volumio wpa_supplicant[2103]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio systemd[1]: mpd.service: Succeeded. Aug 17 12:13:08 volumio systemd[1]: Stopped Music Player Daemon. Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:08 volumio volumio[908]: info: Starting Shairport Sync Aug 17 12:13:08 volumio sudo[2295]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 17 12:13:08 volumio sudo[2295]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:08 volumio systemd[1]: Starting Music Player Daemon... Aug 17 12:13:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 17 12:13:08 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 17 12:13:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 17 12:13:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 17 12:13:08 volumio sudo[2295]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:08 volumio volumio[908]: info: Shairport-Sync Started Aug 17 12:13:09 volumio wpa_supplicant[2103]: wlan0: CTRL-EVENT-TERMINATING Aug 17 12:13:09 volumio sudo[2289]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 17 12:13:09 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:09 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:10 volumio mpd[2301]: Aug 17 12:13 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 17 12:13:10 volumio systemd[1]: Started Music Player Daemon. Aug 17 12:13:10 volumio sudo[2284]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:10 volumio volumio[908]: error: updateQueue error: null Aug 17 12:13:11 volumio sudo[2307]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip addr flush dev wlan0 Aug 17 12:13:11 volumio sudo[2307]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:11 volumio sudo[2307]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:11 volumio sudo[2309]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 down Aug 17 12:13:11 volumio sudo[2309]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:11 volumio sudo[2309]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:11 volumio avahi-daemon[662]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. Aug 17 12:13:11 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled Aug 17 12:13:11 volumio avahi-daemon[662]: New relevant interface wlan0.IPv4 for mDNS. Aug 17 12:13:11 volumio avahi-daemon[662]: Registering new address record for 192.168.211.1 on wlan0.IPv4. Aug 17 12:13:11 volumio systemd[1]: Starting Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator... Aug 17 12:13:11 volumio hostapd[2315]: Configuration file: /etc/hostapd/hostapd.conf Aug 17 12:13:11 volumio hostapd[2315]: wlan0: Could not connect to kernel driver Aug 17 12:13:11 volumio hostapd[2315]: Using interface wlan0 with hwaddr dc:a6:32:fd:76:b1 and ssid "Volumio-97886" Aug 17 12:13:11 volumio dhcpcd[2146]: wlan0: carrier acquired Aug 17 12:13:11 volumio hostapd[2315]: wlan0: interface state UNINITIALIZED->ENABLED Aug 17 12:13:11 volumio hostapd[2315]: wlan0: AP-ENABLED Aug 17 12:13:11 volumio systemd[1]: Started Advanced IEEE 802.11 AP and IEEE 802.1X/WPA/WPA2/EAP Authenticator. Aug 17 12:13:11 volumio dhcpcd[2146]: wlan0: IAID 32:fd:76:b1 Aug 17 12:13:11 volumio dhcpcd[2146]: wlan0: adding address fe80::5017:cdb4:a7b:2bf9 Aug 17 12:13:11 volumio dhcpcd[2146]: ipv6_addaddr1: Permission denied Aug 17 12:13:12 volumio iwconfig[2320]: Error for wireless request "Set Power Management" (8B2C) : Aug 17 12:13:12 volumio iwconfig[2320]: SET failed on device wlan0 ; Invalid argument. Aug 17 12:13:12 volumio systemd[1]: Started Wireless Services. Aug 17 12:13:12 volumio sudo[2034]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:12 volumio volumio[908]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Aug 17 12:13:12 volumio volumio[908]: info: CoreStateMachine::getcurrentVolume Aug 17 12:13:12 volumio volumio[908]: info: CoreCommandRouter::volumioRetrievevolume Aug 17 12:13:12 volumio volumio[908]: info: CoreStateMachine::pushState Aug 17 12:13:12 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:12 volumio volumio[908]: info: CoreCommandRouter::volumioPushState Aug 17 12:13:12 volumio volumio[908]: info: Discovery: this is already registered, 83650003-a6b7-4fa1-8cc1-bc549b10a0f4 Aug 17 12:13:12 volumio volumio[908]: info: Discovery: Found device Volumio Aug 17 12:13:12 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:12 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:12 volumio dhcpcd[2146]: wlan0: soliciting a DHCP lease Aug 17 12:13:12 volumio dhcpcd[2146]: wlan0: soliciting an IPv6 router Aug 17 12:13:13 volumio ntpd[805]: Listen normally on 7 wlan0 192.168.211.1:123 Aug 17 12:13:13 volumio ntpd[805]: new interface(s) found: waking up resolver Aug 17 12:13:15 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:15 volumio volumio[908]: info: Retrieving Cloud Streaming UI Aug 17 12:13:15 volumio volumio[908]: info: Getting Tidal Cloud Configuration Aug 17 12:13:15 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:15 volumio volumio[908]: info: Getting Qobuz Cloud Configuration Aug 17 12:13:15 volumio volumio[908]: info: Asking plugin for UI Config Aug 17 12:13:15 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:15 volumio volumio[908]: info: Getting Spotify Cloud Configuration Aug 17 12:13:15 volumio volumio[908]: info: Asking plugin for UI Config Aug 17 12:13:15 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:15 volumio volumio[908]: info: Saving Spotify Acccount Aug 17 12:13:15 volumio volumio[908]: info: Got Tidal Cloud Configuration Aug 17 12:13:15 volumio volumio[908]: info: Got it Aug 17 12:13:15 volumio volumio[908]: info: Got it Aug 17 12:13:15 volumio volumio[908]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Aug 17 12:13:15 volumio volumio[908]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 17 12:13:15 volumio volumio[908]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Aug 17 12:13:17 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , reportWirelessConnection Aug 17 12:13:17 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessInfo Aug 17 12:13:17 volumio sudo[2323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 17 12:13:17 volumio sudo[2323]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:17 volumio sudo[2323]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:17 volumio dhcpcd[2146]: wlan0: probing for an IPv4LL address Aug 17 12:13:19 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonation Aug 17 12:13:19 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Aug 17 12:13:19 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , getDonationsArray Aug 17 12:13:19 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , getDoneMessage Aug 17 12:13:19 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware Aug 17 12:13:22 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: upnp , onRestart Aug 17 12:13:22 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , onNetworkingRestart Aug 17 12:13:22 volumio volumio[908]: info: Refreshing Cached IP Addresses Aug 17 12:13:22 volumio sudo[2332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Aug 17 12:13:22 volumio sudo[2332]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:22 volumio systemd[1]: upmpdcli.service: Succeeded. Aug 17 12:13:22 volumio sudo[2332]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:22 volumio sudo[2335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 17 12:13:22 volumio sudo[2335]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:22 volumio sudo[2335]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:22 volumio sudo[2338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 17 12:13:22 volumio sudo[2338]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:22 volumio sudo[2338]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:22 volumio dhcpcd[2146]: wlan0: using IPv4LL address 169.254.9.191 Aug 17 12:13:22 volumio avahi-daemon[662]: Registering new address record for 169.254.9.191 on wlan0.IPv4. Aug 17 12:13:22 volumio dhcpcd[2146]: wlan0: adding route to 169.254.0.0/16 Aug 17 12:13:22 volumio volumio[908]: info: CALLMETHOD: system_controller system saveUpdateSettings [object Object] Aug 17 12:13:22 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , saveUpdateSettings Aug 17 12:13:22 volumio volumio[908]: error: Failed callmethod call: TypeError: Cannot read property 'value' of undefined Aug 17 12:13:23 volumio ntpd[805]: Listen normally on 8 wlan0 169.254.9.191:123 Aug 17 12:13:23 volumio ntpd[805]: new interface(s) found: waking up resolver Aug 17 12:13:24 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Aug 17 12:13:24 volumio volumio[908]: info: CoreCommandRouter::Reload Ui Aug 17 12:13:24 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , setShowWizard Aug 17 12:13:24 volumio volumio[908]: info: Wizard terminated Successfully Aug 17 12:13:24 volumio volumio[908]: info: CoreCommandRouter::volumiosetStartupVolume Aug 17 12:13:24 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 17 12:13:24 volumio volumio[908]: info: Player Reboot required after I2S DAC has been enabled in wizard Aug 17 12:13:25 volumio sudo[2360]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 17 12:13:25 volumio sudo[2360]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:25 volumio sudo[2360]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:25 volumio sudo[2363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 17 12:13:25 volumio sudo[2363]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:25 volumio sudo[2363]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:25 volumio volumio[908]: verbose: New Socket.io Connection to 192.168.68.71 from 192.168.68.70 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 4 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetVisibleSources Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 17 12:13:25 volumio volumio[908]: info: Received Get System Info Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 12:13:25 volumio volumio[908]: info: Discovery: Getting this device information Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: Listing playlists Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 17 12:13:25 volumio sudo[2366]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 17 12:13:25 volumio sudo[2366]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:25 volumio sudo[2366]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:25 volumio sudo[2369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 17 12:13:25 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:25 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:25 volumio volumio[908]: verbose: New Socket.io Connection to 192.168.68.71 from 192.168.68.70 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_5_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.5 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 4 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetVisibleSources Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 17 12:13:25 volumio volumio[908]: info: Received Get System Info Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 12:13:25 volumio volumio[908]: info: Discovery: Getting this device information Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:25 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:25 volumio volumio[908]: info: Listing playlists Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 17 12:13:25 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 17 12:13:26 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 17 12:13:27 volumio volumio[908]: info: Received Get System Info Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 12:13:27 volumio volumio[908]: info: Discovery: Getting this device information Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:27 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 17 12:13:27 volumio volumio[908]: info: Received Get System Info Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 12:13:27 volumio volumio[908]: info: Discovery: Getting this device information Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:27 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:27 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 12:13:30 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: wizard , setOnboardingWizardFalse Aug 17 12:13:32 volumio sudo[2372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 17 12:13:32 volumio sudo[2372]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:32 volumio sudo[2372]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:32 volumio sudo[2374]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 17 12:13:32 volumio sudo[2374]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:32 volumio sudo[2374]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:32 volumio sudo[2378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 17 12:13:32 volumio sudo[2378]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 17 12:13:32 volumio volumio[908]: info: CoreCommandRouter::volumioPlay Aug 17 12:13:32 volumio volumio[908]: info: CoreStateMachine::play index undefined Aug 17 12:13:32 volumio volumio[908]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 17 12:13:32 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:32 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Aug 17 12:13:32 volumio sudo[2378]: pam_unix(sudo:session): session closed for user root Aug 17 12:13:32 volumio volumio[908]: info: Upmpdcli Daemon Started Aug 17 12:13:32 volumio volumio[2380]: writing RSA key Aug 17 12:13:35 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 17 12:13:39 volumio volumio[908]: info: CoreCommandRouter::volumioGetQueue Aug 17 12:13:39 volumio volumio[908]: info: CoreStateMachine::getQueue Aug 17 12:13:39 volumio volumio[908]: info: CorePlayQueue::getQueue Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 17 12:13:43 volumio volumio[908]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 17 12:13:43 volumio volumio[908]: info: Received Get System Version Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 17 12:13:43 volumio volumio[908]: info: Received Get System Info Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 17 12:13:43 volumio volumio[908]: info: Discovery: Getting this device information Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::volumioGetState Aug 17 12:13:43 volumio volumio[908]: info: CorePlayQueue::getTrack 0 Aug 17 12:13:43 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 17 12:13:46 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 17 12:13:46 volumio volumio[908]: info: Preload queue cleared Aug 17 12:13:48 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 17 12:13:48 volumio volumio[908]: info: Preload queue cleared Aug 17 12:13:49 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 17 12:13:49 volumio volumio[908]: info: Preload queue cleared Aug 17 12:13:55 volumio volumio[908]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Aug 17 12:13:55 volumio volumio[908]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 17 12:13:55 volumio volumio[908]: TypeError: Cannot read property 'length' of undefined Aug 17 12:13:55 volumio volumio[908]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Aug 17 12:13:55 volumio volumio[908]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Aug 17 12:13:55 volumio volumio[908]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Aug 17 12:13:55 volumio volumio[908]: at Parser.emit (events.js:315:20) Aug 17 12:13:55 volumio volumio[908]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Aug 17 12:13:55 volumio volumio[908]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Aug 17 12:13:55 volumio volumio[908]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Aug 17 12:13:55 volumio volumio[908]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Aug 17 12:13:55 volumio volumio[908]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Aug 17 12:13:55 volumio volumio[908]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Aug 17 12:13:55 volumio volumio[908]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Aug 17 12:13:55 volumio volumio[908]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Aug 17 12:13:55 volumio volumio[908]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Aug 17 12:13:55 volumio volumio[908]: at IncomingMessage.emit (events.js:327:22) Aug 17 12:13:55 volumio volumio[908]: at endReadableNT (internal/streams/readable.js:1327:12) Aug 17 12:13:55 volumio volumio[908]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Aug 17 12:13:55 volumio volumio[908]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 17 12:13:55 volumio sudo[2480]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-17 12:12 Aug 17 12:13:55 volumio sudo[2480]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"