May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::volumioGetBrowseSources May 30 12:28:00 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 12:28:01 volumio volumio[1086]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 30 12:28:01 volumio volumio[1086]: info: Completed starting MyVolumio Plugin May 30 12:28:01 volumio volumio[1086]: [Metrics] CommandRouter: 54s 95.98ms May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::volumiosetStartupVolume May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::Close All Modals sent May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::Close All Modals sent May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Retrieving Cloud Streaming UI May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Retrieving Cloud Streaming UI May 30 12:28:01 volumio volumio[1086]: info: Getting Tidal Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Getting Qobuz Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Getting Spotify Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Saving Spotify Acccount May 30 12:28:01 volumio volumio[1086]: info: Got Tidal Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Got it May 30 12:28:01 volumio volumio[1086]: info: Got it May 30 12:28:01 volumio volumio[1086]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 30 12:28:01 volumio volumio[1086]: info: Getting Tidal Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Getting Qobuz Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Getting Spotify Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: info: Saving Spotify Acccount May 30 12:28:01 volumio volumio[1086]: info: Got Tidal Cloud Configuration May 30 12:28:01 volumio volumio[1086]: info: Got it May 30 12:28:01 volumio volumio[1086]: info: Got it May 30 12:28:01 volumio volumio[1086]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 30 12:28:01 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:01 volumio volumio[1086]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 30 12:28:02 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 30 12:28:02 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 12:28:02 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 30 12:28:02 volumio volumio[1086]: info: Version has changed, forcing UI Reload May 30 12:28:02 volumio volumio[1086]: info: CoreCommandRouter::Reload Ui May 30 12:28:02 volumio sudo[2272]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 12:28:02 volumio sudo[2272]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:02 volumio sudo[2274]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 30 12:28:02 volumio sudo[2274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:02 volumio sudo[2272]: pam_unix(sudo:session): session closed for user root May 30 12:28:02 volumio sudo[2274]: pam_unix(sudo:session): session closed for user root May 30 12:28:02 volumio volumio[1086]: verbose: New Socket.io Connection to 192.168.0.43 from 192.168.0.66 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 74 May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::volumioGetVisibleSources May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones May 30 12:28:03 volumio volumio[1086]: info: Received Get System Info May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 12:28:03 volumio volumio[1086]: info: Discovery: Getting this device information May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState May 30 12:28:03 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 12:28:03 volumio volumio-remote-updater[695]: No test mode May 30 12:28:03 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:03 volumio volumio[1086]: info: Retrieving Cloud Streaming UI May 30 12:28:03 volumio volumio[1086]: info: Getting Tidal Cloud Configuration May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:03 volumio volumio[1086]: info: Getting Qobuz Cloud Configuration May 30 12:28:03 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:03 volumio volumio[1086]: info: Getting Spotify Cloud Configuration May 30 12:28:03 volumio volumio[1086]: info: Asking plugin for UI Config May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:03 volumio volumio[1086]: info: Saving Spotify Acccount May 30 12:28:03 volumio volumio[1086]: info: Got Tidal Cloud Configuration May 30 12:28:03 volumio volumio[1086]: info: Got it May 30 12:28:03 volumio volumio[1086]: info: Got it May 30 12:28:03 volumio volumio[1086]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:03 volumio volumio[1086]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') May 30 12:28:03 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:03 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:04 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 30 12:28:04 volumio volumio[1086]: info: Loading i18n strings for locale zh May 30 12:28:04 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 30 12:28:04 volumio volumio[1086]: info: Setting timezone to Asia/Taipei May 30 12:28:04 volumio sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 30 12:28:04 volumio sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:04 volumio sudo[2285]: pam_unix(sudo:session): session closed for user root May 30 12:28:04 volumio sudo[2289]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Taipei /etc/localtime May 30 12:28:04 volumio sudo[2289]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:04 volumio sudo[2289]: pam_unix(sudo:session): session closed for user root May 30 12:28:04 volumio sudo[2293]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 30 12:28:04 volumio sudo[2293]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:04 volumio sudo[2293]: pam_unix(sudo:session): session closed for user root May 30 12:28:04 volumio sudo[2297]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Taipei May 30 12:28:04 volumio sudo[2297]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:04 volumio sudo[2297]: pam_unix(sudo:session): session closed for user root May 30 12:28:04 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:28:04 volumio volumio[1086]: Updating browse sources language May 30 12:28:04 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 12:28:04 volumio volumio[1086]: info: Fetching Streaming Services browse cache May 30 12:28:05 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:28:08 volumio volumio[1086]: info: BOOT COMPLETED May 30 12:28:10 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 30 12:28:10 volumio volumio[1086]: info: Loading i18n strings for locale zh_TW May 30 12:28:10 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 30 12:28:10 volumio volumio[1086]: info: Setting timezone to Asia/Taipei May 30 12:28:10 volumio sudo[2315]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 30 12:28:10 volumio sudo[2315]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:10 volumio sudo[2315]: pam_unix(sudo:session): session closed for user root May 30 12:28:10 volumio sudo[2319]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Taipei /etc/localtime May 30 12:28:10 volumio sudo[2319]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:10 volumio sudo[2319]: pam_unix(sudo:session): session closed for user root May 30 12:28:10 volumio sudo[2323]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 30 12:28:10 volumio sudo[2323]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:10 volumio sudo[2323]: pam_unix(sudo:session): session closed for user root May 30 12:28:10 volumio sudo[2327]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Taipei May 30 12:28:10 volumio sudo[2327]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:10 volumio sudo[2327]: pam_unix(sudo:session): session closed for user root May 30 12:28:11 volumio volumio[1086]: Updating browse sources language May 30 12:28:11 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 12:28:11 volumio volumio[1086]: info: Fetching Streaming Services browse cache May 30 12:28:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage May 30 12:28:12 volumio volumio[1086]: info: Loading i18n strings for locale zh_TW May 30 12:28:12 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone May 30 12:28:12 volumio volumio[1086]: info: Setting timezone to Asia/Taipei May 30 12:28:12 volumio sudo[2332]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime May 30 12:28:12 volumio sudo[2332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:12 volumio sudo[2332]: pam_unix(sudo:session): session closed for user root May 30 12:28:12 volumio sudo[2336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Asia/Taipei /etc/localtime May 30 12:28:12 volumio sudo[2336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:12 volumio sudo[2336]: pam_unix(sudo:session): session closed for user root May 30 12:28:12 volumio sudo[2340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime May 30 12:28:12 volumio sudo[2340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:12 volumio sudo[2340]: pam_unix(sudo:session): session closed for user root May 30 12:28:12 volumio sudo[2344]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Asia/Taipei May 30 12:28:12 volumio sudo[2344]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:13 volumio sudo[2344]: pam_unix(sudo:session): session closed for user root May 30 12:28:13 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache May 30 12:28:13 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks May 30 12:28:13 volumio sudo[2347]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 30 12:28:13 volumio volumio[1086]: Updating browse sources language May 30 12:28:13 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 12:28:13 volumio sudo[2347]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:13 volumio volumio[1086]: info: Fetching Streaming Services browse cache May 30 12:28:15 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings May 30 12:28:15 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAudioDevices May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:16 volumio volumio-remote-updater[695]: No test mode May 30 12:28:16 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:16 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:16 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:17 volumio sudo[2347]: pam_unix(sudo:session): session closed for user root May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 30 12:28:21 volumio volumio[1086]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 30 12:28:21 volumio volumio[1086]: info: Received Get System Version May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 12:28:21 volumio volumio[1086]: info: Received Get System Info May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 12:28:21 volumio volumio[1086]: info: Discovery: Getting this device information May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState May 30 12:28:21 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:21 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 12:28:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:22 volumio volumio-remote-updater[695]: No test mode May 30 12:28:22 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:22 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:23 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:23 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:24 volumio volumio-remote-updater[695]: No test mode May 30 12:28:24 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:24 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:25 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:25 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 30 12:28:27 volumio volumio[1086]: info: Preparing to save Alsa Options, stopping services first May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::volumioGetState May 30 12:28:27 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::volumioPause May 30 12:28:27 volumio volumio[1086]: info: CoreStateMachine::pause May 30 12:28:27 volumio volumio[1086]: info: Saving Audio Output to: {"i2s":true,"i2sid":{"value":"soekris-dac","label":"Soekris dam 1021"},"output_device":{"value":1,"label":"Soekris dam 1021"},"disallowPush":true} May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:27 volumio volumio[1086]: info: Enabling I2S DAC: Soekris dam 1021 May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:27 volumio sudo[2371]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l May 30 12:28:27 volumio sudo[2371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:27 volumio sudo[2371]: pam_unix(sudo:session): session closed for user root May 30 12:28:27 volumio volumio[1086]: info: No Overlays Loaded May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:27 volumio sudo[2374]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dac May 30 12:28:27 volumio sudo[2374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/i2s@7e203000/status May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/#sound-dai-cells May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/compatible May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /pcm5102a-codec/status May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller May 30 12:28:27 volumio kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status May 30 12:28:27 volumio volumio[1086]: info: Device 2 does not have any Mixer Control Available May 30 12:28:27 volumio sudo[2374]: pam_unix(sudo:session): session closed for user root May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 30 12:28:27 volumio volumio[1086]: info: Updating Volume Controller Parameters: Device: 2 Name: Soekris dam 1021 Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 30 12:28:27 volumio volumio[1086]: info: Disabling external Volume Control May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction May 30 12:28:27 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:27 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:27 volumio volumio[1086]: info: Preparing to generate the ALSA configuration file May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks May 30 12:28:27 volumio volumio[1086]: info: May 30 12:28:27 volumio volumio[1086]: ---------------------------- MPD announces state update: mixer May 30 12:28:27 volumio volumio[1086]: info: ControllerMpd::getState May 30 12:28:27 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand status May 30 12:28:27 volumio volumio[1086]: info: May 30 12:28:27 volumio volumio[1086]: ---------------------------- MPD announces state update: mixer May 30 12:28:27 volumio volumio[1086]: info: ControllerMpd::getState May 30 12:28:27 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand status May 30 12:28:27 volumio volumio[1086]: info: May 30 12:28:27 volumio volumio[1086]: ---------------------------- MPD announces state update: mixer May 30 12:28:27 volumio volumio[1086]: info: ControllerMpd::getState May 30 12:28:27 volumio volumio[1086]: verbose: ControllerMpd::sendMpdCommand status May 30 12:28:27 volumio volumio[1086]: info: sendMpdCommand status took 3 milliseconds May 30 12:28:27 volumio volumio[1086]: info: sendMpdCommand status took 2 milliseconds May 30 12:28:27 volumio volumio[1086]: verbose: ControllerMpd::parseState May 30 12:28:27 volumio volumio[1086]: verbose: ControllerMpd::parseState May 30 12:28:27 volumio volumio[1086]: info: ControllerMpd::pushState May 30 12:28:27 volumio volumio[1086]: info: CoreCommandRouter::servicePushState May 30 12:28:28 volumio sudo[2397]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 30 12:28:28 volumio sudo[2397]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio sudo[2395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 30 12:28:28 volumio sudo[2395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: 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} May 30 12:28:28 volumio volumio[1086]: verbose: CURRENT POSITION 0 May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState stateService stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState currentStatus stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: No code May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio sudo[2397]: pam_unix(sudo:session): session closed for user root May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: ControllerMpd::pushState May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::servicePushState May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: 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} May 30 12:28:28 volumio volumio[1086]: verbose: CURRENT POSITION 0 May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState stateService stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState currentStatus stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: No code May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: ------------------------------ 149ms May 30 12:28:28 volumio volumio[1086]: info: ------------------------------ 147ms May 30 12:28:28 volumio volumio[1086]: info: I2S Param [object Object] successfully enabled May 30 12:28:28 volumio volumio[1086]: info: sendMpdCommand status took 183 milliseconds May 30 12:28:28 volumio volumio[1086]: verbose: ControllerMpd::parseState May 30 12:28:28 volumio volumio[1086]: info: ControllerMpd::pushState May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::servicePushState May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: 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} May 30 12:28:28 volumio volumio[1086]: verbose: CURRENT POSITION 0 May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState stateService stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::syncState currentStatus stop May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: No code May 30 12:28:28 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:28 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:28 volumio volumio[1086]: info: ------------------------------ 245ms May 30 12:28:28 volumio volumio[1086]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 30 12:28:28 volumio volumio[1086]: wlan0 Interface doesn't support scanning : Device or resource busy May 30 12:28:28 volumio volumio[1086]: info: Cannot use regular scanning, forcing with ap-force May 30 12:28:28 volumio sudo[2403]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 30 12:28:28 volumio sudo[2403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio sudo[2403]: pam_unix(sudo:session): session closed for user root May 30 12:28:28 volumio volumio[1086]: command failed: Device or resource busy (-16) May 30 12:28:28 volumio volumio[1086]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 30 12:28:28 volumio volumio[1086]: command failed: Device or resource busy (-16) May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 30 12:28:28 volumio volumio[1086]: info: Getting Alsa Cards List without I2S DAC May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 30 12:28:28 volumio volumio[1086]: info: Asound.conf file written May 30 12:28:28 volumio sudo[2421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 30 12:28:28 volumio sudo[2421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio sudo[2421]: pam_unix(sudo:session): session closed for user root May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: No state is present for card b1 May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: /usr/share/alsa/init/bcm2835:14: control element not found May 30 12:28:28 volumio volumio[1086]: No state is present for card b1 May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: No state is present for card Headphones May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: /usr/share/alsa/init/bcm2835:20: control element not found May 30 12:28:28 volumio volumio[1086]: No state is present for card Headphones May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: No state is present for card sndrpihifiberry May 30 12:28:28 volumio volumio[1086]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2 May 30 12:28:28 volumio volumio[1086]: Found hardware: "RPi-simple" "" "" "" "" May 30 12:28:28 volumio volumio[1086]: Hardware is initialized using a generic method May 30 12:28:28 volumio volumio[1086]: No state is present for card sndrpihifiberry May 30 12:28:28 volumio volumio[1086]: info: Output device has changed, restarting MPD May 30 12:28:28 volumio volumio[1086]: info: Output device has changed, restarting Shairport Sync May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 12:28:28 volumio volumio[1086]: info: Output device has changed, restarting MPD May 30 12:28:28 volumio sudo[2427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 12:28:28 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio sudo[2429]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 12:28:28 volumio sudo[2429]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio sudo[2427]: pam_unix(sudo:session): session closed for user root May 30 12:28:28 volumio volumio[1086]: info: Output device has changed, restarting Shairport Sync May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio sudo[2436]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 30 12:28:28 volumio sudo[2436]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:28 volumio sudo[2439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 30 12:28:28 volumio sudo[2439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:28 volumio sudo[2436]: pam_unix(sudo:session): session closed for user root May 30 12:28:28 volumio volumio[1086]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 30 12:28:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 30 12:28:28 volumio volumio[1086]: info: MPD Permissions set May 30 12:28:28 volumio volumio[1086]: info: MPD Permissions set May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:28 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:28:29 volumio volumio[1086]: info: Starting Shairport Sync May 30 12:28:29 volumio volumio[1086]: info: Starting Shairport Sync May 30 12:28:29 volumio sudo[2458]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 12:28:29 volumio sudo[2458]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:29 volumio systemd[1]: mpd.service: Deactivated successfully. May 30 12:28:29 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 30 12:28:29 volumio systemd[1]: mpd.service: Consumed 3.278s CPU time. May 30 12:28:29 volumio systemd[1]: mpd.socket: Deactivated successfully. May 30 12:28:29 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 30 12:28:29 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 30 12:28:29 volumio sudo[2461]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 30 12:28:29 volumio sudo[2461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:29 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 30 12:28:29 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 30 12:28:29 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 30 12:28:29 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 30 12:28:29 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 12:28:29 volumio systemd[1]: shairport-sync.service: Consumed 1.610s CPU time. May 30 12:28:29 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 30 12:28:29 volumio sudo[2461]: pam_unix(sudo:session): session closed for user root May 30 12:28:29 volumio sudo[2458]: pam_unix(sudo:session): session closed for user root May 30 12:28:29 volumio volumio[1086]: info: Shairport-Sync Started May 30 12:28:29 volumio volumio[1086]: info: Shairport-Sync Started May 30 12:28:29 volumio sudo[2464]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 30 12:28:29 volumio sudo[2464]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:29 volumio sudo[2464]: pam_unix(sudo:session): session closed for user root May 30 12:28:30 volumio mpd[2481]: 2025-05-30T12:28:30 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 30 12:28:30 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 30 12:28:30 volumio sudo[2429]: pam_unix(sudo:session): session closed for user root May 30 12:28:30 volumio sudo[2439]: pam_unix(sudo:session): session closed for user root May 30 12:28:30 volumio volumio[1086]: error: MPD error: The expression evaluated to a falsy value: May 30 12:28:30 volumio volumio[1086]: assert.ok(self.idling) May 30 12:28:30 volumio volumio[1086]: error: The expression evaluated to a falsy value: May 30 12:28:30 volumio volumio[1086]: assert.ok(self.idling) May 30 12:28:30 volumio volumio[1086]: error: updateQueue error: null May 30 12:28:31 volumio volumio[1086]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 30 12:28:31 volumio volumio[1086]: info: CoreStateMachine::getcurrentVolume May 30 12:28:31 volumio volumio[1086]: info: CoreCommandRouter::volumioRetrievevolume May 30 12:28:31 volumio volumio[1086]: info: CoreStateMachine::pushState May 30 12:28:31 volumio volumio[1086]: info: CorePlayQueue::getTrack 0 May 30 12:28:31 volumio volumio[1086]: info: CoreCommandRouter::volumioPushState May 30 12:28:32 volumio sudo[2395]: pam_unix(sudo:session): session closed for user root May 30 12:28:34 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:34 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:34 volumio volumio-remote-updater[695]: No test mode May 30 12:28:34 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:34 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:35 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:35 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:40 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:40 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:41 volumio volumio-remote-updater[695]: No test mode May 30 12:28:41 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:41 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:41 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:41 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:43 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , clearUpdateSchedule May 30 12:28:43 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 30 12:28:43 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 30 12:28:43 volumio volumio-remote-updater[695]: No test mode May 30 12:28:43 volumio volumio-remote-updater[695]: No alpha test mode May 30 12:28:43 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 30 12:28:43 volumio volumio[1086]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 30 12:28:43 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 30 12:28:52 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: wizard , connectWirelessNetwork May 30 12:28:52 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , getWiredInfo May 30 12:28:52 volumio sudo[2532]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 30 12:28:52 volumio sudo[2532]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:52 volumio sudo[2532]: pam_unix(sudo:session): session closed for user root May 30 12:28:52 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: network , saveWirelessNetworkSettings May 30 12:28:52 volumio volumio[1086]: info: Saving new wireless network May 30 12:28:52 volumio sudo[2535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/wpa_supplicant/wpa_supplicant.conf May 30 12:28:52 volumio sudo[2535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:52 volumio sudo[2535]: pam_unix(sudo:session): session closed for user root May 30 12:28:52 volumio volumio[1086]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , onNetworkingRestart May 30 12:28:52 volumio volumio[1086]: info: Discovery: Restarting Advertising due to device name change May 30 12:28:52 volumio sudo[2538]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart wireless.service May 30 12:28:52 volumio sudo[2538]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:52 volumio systemd[1]: Starting wireless.service - Wireless Services... May 30 12:28:53 volumio volumio[1086]: info: Discovery: A device disappeared from network May 30 12:28:53 volumio volumio[1086]: info: Discovery: Device volumio disappeared from network May 30 12:28:53 volumio volumio[1086]: info: Discovery: A device disappeared from network May 30 12:28:53 volumio volumio[1086]: info: Discovery: A device disappeared from network May 30 12:28:53 volumio systemd[1]: Stopping dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server... May 30 12:28:53 volumio dnsmasq[1998]: exiting on receipt of SIGTERM May 30 12:28:53 volumio systemd[1]: dnsmasq.service: Deactivated successfully. May 30 12:28:53 volumio systemd[1]: Stopped dnsmasq.service - dnsmasq - A lightweight DHCP and caching DNS server. May 30 12:28:53 volumio systemd[1]: Stopping hostapd.service - Access point and authentication server for Wi-Fi and Ethernet... May 30 12:28:53 volumio dhcpcd[834]: wlan0: carrier lost May 30 12:28:53 volumio systemd[1]: hostapd.service: Deactivated successfully. May 30 12:28:53 volumio systemd[1]: Stopped hostapd.service - Access point and authentication server for Wi-Fi and Ethernet. May 30 12:28:54 volumio avahi-daemon[684]: Withdrawing address record for 169.254.38.36 on wlan0. May 30 12:28:54 volumio dhcpcd[834]: wlan0: deleting route to 169.254.0.0/16 May 30 12:28:54 volumio sudo[2570]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 30 12:28:54 volumio sudo[2570]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:54 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 30 12:28:54 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 30 12:28:54 volumio systemd[1]: welcome.service: Deactivated successfully. May 30 12:28:54 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 30 12:28:54 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 30 12:28:54 volumio avahi-daemon[684]: Withdrawing address record for 192.168.211.1 on wlan0. May 30 12:28:54 volumio avahi-daemon[684]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.211.1. May 30 12:28:54 volumio avahi-daemon[684]: Interface wlan0.IPv4 no longer relevant for mDNS. May 30 12:28:54 volumio sudo[2570]: pam_unix(sudo:session): session closed for user root May 30 12:28:54 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 30 12:28:54 volumio welcome[2589]: Resolved ip:[1] 192.168.0.43 May 30 12:28:54 volumio sudo[2599]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 30 12:28:54 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 30 12:28:54 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 30 12:28:54 volumio sudo[2599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:54 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0. May 30 12:28:54 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0... May 30 12:28:54 volumio systemd[1]: welcome.service: Deactivated successfully. May 30 12:28:54 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 30 12:28:54 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 30 12:28:54 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 30 12:28:54 volumio welcome[2615]: Resolved ip:[1] 192.168.0.43 May 30 12:28:54 volumio sudo[2599]: pam_unix(sudo:session): session closed for user root May 30 12:28:54 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 30 12:28:54 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0. May 30 12:28:55 volumio sudo[2626]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 30 12:28:55 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:55 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 30 12:28:55 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root May 30 12:28:55 volumio sudo[2628]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg get May 30 12:28:55 volumio sudo[2628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:55 volumio sudo[2628]: pam_unix(sudo:session): session closed for user root May 30 12:28:55 volumio sudo[2636]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 30 12:28:55 volumio sudo[2636]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:55 volumio sudo[2636]: pam_unix(sudo:session): session closed for user root May 30 12:28:55 volumio sudo[2638]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw wlan0 scan May 30 12:28:55 volumio sudo[2638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:56 volumio ntpd[915]: IO: Deleting interface #6 wlan0, 192.168.211.1#123, interface stats: received=0, sent=0, dropped=0, active_time=88 secs May 30 12:28:56 volumio ntpd[915]: IO: Deleting interface #7 wlan0, 169.254.38.36#123, interface stats: received=0, sent=0, dropped=0, active_time=76 secs May 30 12:28:57 volumio volumio[1086]: info: Discovery: Started advertising with name: Volumio May 30 12:28:58 volumio sudo[2638]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio sudo[2645]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 up May 30 12:28:58 volumio sudo[2645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:58 volumio sudo[2645]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio sudo[2647]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw reg set TW May 30 12:28:58 volumio sudo[2647]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:58 volumio sudo[2647]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio sudo[2656]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ip addr flush dev wlan0 May 30 12:28:58 volumio sudo[2656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:58 volumio volumio[1086]: compat.c: read() failed: Resource temporarily unavailable May 30 12:28:58 volumio volumio[1086]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 12:28:58 volumio volumio[1086]: Error: dns service error: unknown May 30 12:28:58 volumio volumio[1086]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { May 30 12:28:58 volumio volumio[1086]: errorCode: -65537 May 30 12:28:58 volumio volumio[1086]: } May 30 12:28:58 volumio volumio[1086]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 12:28:58 volumio sudo[2656]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio sudo[2661]: root : PWD=/ ; USER=root ; COMMAND=/usr/sbin/ifconfig wlan0 down May 30 12:28:58 volumio sudo[2661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:58 volumio sudo[2661]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio wpa_supplicant[2674]: Successfully initialized wpa_supplicant May 30 12:28:58 volumio sudo[2676]: root : PWD=/ ; USER=root ; COMMAND=/sbin/dhcpcd May 30 12:28:58 volumio sudo[2676]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:58 volumio dhcpcd[834]: control command: /sbin/dhcpcd May 30 12:28:58 volumio dhcpcd[834]: control_free: No such file or directory May 30 12:28:58 volumio sudo[2676]: pam_unix(sudo:session): session closed for user root May 30 12:28:58 volumio kernel: brcmfmac: brcmf_cfg80211_set_power_mgmt: power save disabled May 30 12:28:58 volumio dhcpcd[834]: lo: IAID 00:00:00:00 May 30 12:28:58 volumio dhcpcd[834]: lo: adding address fe80::38f2:6b66:2cba:e91b May 30 12:28:58 volumio dhcpcd[834]: ipv6_addaddr1: Permission denied May 30 12:28:58 volumio dhcpcd[834]: lo: using static address 127.0.0.1/8 May 30 12:28:58 volumio dhcpcd[834]: lo: adding route to 127.0.0.0/8 May 30 12:28:59 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 30 12:28:59 volumio systemd[1]: Reached target ip-changed@lo.target - IP Address changed on lo. May 30 12:28:59 volumio systemd[1]: Stopped target ip-changed@eth0.target - IP Address changed on eth0. May 30 12:28:59 volumio systemd[1]: Stopping ip-changed@eth0.target - IP Address changed on eth0... May 30 12:28:59 volumio systemd[1]: welcome.service: Deactivated successfully. May 30 12:28:59 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console. May 30 12:28:59 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console... May 30 12:28:59 volumio systemd[1]: Starting welcome.service - Show a welcome message on console... May 30 12:28:59 volumio dbus-daemon[686]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.41' (uid=0 pid=2709 comm="timedatectl show --property=NTPSynchronized --valu") May 30 12:28:59 volumio welcome[2719]: Resolved ip:[1] 192.168.0.43 May 30 12:28:59 volumio wpa_supplicant[2674]: nl80211: kernel reports: Registration to specific type not supported May 30 12:28:59 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 30 12:28:59 volumio systemd[1]: Finished welcome.service - Show a welcome message on console. May 30 12:28:59 volumio systemd[1]: Reached target ip-changed@eth0.target - IP Address changed on eth0. May 30 12:28:59 volumio dbus-daemon[686]: [system] Successfully activated service 'org.freedesktop.timedate1' May 30 12:28:59 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 30 12:28:59 volumio setdatetime-helper.sh[2691]: Time is not synchronized. Attempting to sync... May 30 12:28:59 volumio sudo[2765]: root : PWD=/ ; USER=root ; COMMAND=/usr/bin/date -s 'Fri, 30 May 2025 04:28:59 GMT#015' May 30 12:28:59 volumio sudo[2765]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 30 12:28:59 volumio setdatetime-helper.sh[2766]: Fri May 30 12:28:59 CST 2025 May 30 12:28:59 volumio systemd-journald[365]: Time jumped backwards, rotating. May 30 12:28:59 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 30 12:28:59 volumio setdatetime-helper.sh[2691]: Time synchronized successfully. May 30 12:28:59 volumio sudo[2765]: pam_unix(sudo:session): session closed for user root May 30 12:28:59 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 30 12:28:59 volumio sudo[2770]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 30 12:28:59 volumio sudo[2770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:28:59 volumio sudo[2770]: pam_unix(sudo:session): session closed for user root May 30 12:29:00 volumio sudo[2774]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r May 30 12:29:00 volumio sudo[2774]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 30 12:29:00 volumio sudo[2774]: pam_unix(sudo:session): session closed for user root May 30 12:29:00 volumio sudo[2780]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-30 12:28' May 30 12:29:00 volumio sudo[2780]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="1da895bfdbb6eb90d965df32a25a3568df7c84ed" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu May 29 13:12:59 UTC 2025" VOLUMIO_VERSION="4.004" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2df63d74196e499fa1e34fb765df1cca"