-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sat 2025-09-06 07:57:39 CEST. -- Sep 06 07:56:00 volumio volumio[957]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 06 07:56:00 volumio volumio[957]: info: Updating MyVolumio device info Sep 06 07:56:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:01 volumio volumio[957]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 06 07:56:04 volumio volumio[957]: info: MYVOLUMIO: Adding device Sep 06 07:56:04 volumio volumio[957]: info: MYVOLUMIO: Evaluating Server Sep 06 07:56:05 volumio volumio[957]: info: Setting Geolocation for MyVolumio to eu6 Sep 06 07:56:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 06 07:56:06 volumio volumio[957]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Sep 06 07:56:06 volumio volumio-remote-updater[594]: No test mode Sep 06 07:56:06 volumio volumio-remote-updater[594]: No alpha test mode Sep 06 07:56:06 volumio volumio[957]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Sep 06 07:56:06 volumio volumio[957]: info: Updating MyVolumio device info Sep 06 07:56:06 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:06 volumio ntpd[780]: Soliciting pool server 185.123.84.51 Sep 06 07:56:07 volumio volumio[957]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Sep 06 07:56:07 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 07:56:07 volumio volumio[957]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Sep 06 07:56:07 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:07 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:07 volumio ntpd[780]: Soliciting pool server 146.59.232.28 Sep 06 07:56:08 volumio volumio[957]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Sep 06 07:56:08 volumio ntpd[780]: Soliciting pool server 162.159.200.123 Sep 06 07:56:08 volumio ntpd[780]: Soliciting pool server 51.68.44.27 Sep 06 07:56:08 volumio ntpd[780]: Soliciting pool server 141.95.171.142 Sep 06 07:56:09 volumio ntpd[780]: Soliciting pool server 82.66.156.239 Sep 06 07:56:09 volumio ntpd[780]: Soliciting pool server 109.190.177.203 Sep 06 07:56:09 volumio ntpd[780]: Soliciting pool server 45.90.162.253 Sep 06 07:56:10 volumio ntpd[780]: Soliciting pool server 82.64.131.93 Sep 06 07:56:10 volumio ntpd[780]: Soliciting pool server 45.13.105.44 Sep 06 07:56:11 volumio ntpd[780]: Soliciting pool server 82.67.62.62 Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::volumioGetBrowseSources Sep 06 07:56:12 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 06 07:56:12 volumio volumio[957]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; CrOS armv7l 13597.84.0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.98 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Sep 06 07:56:12 volumio ntpd[780]: Soliciting pool server 2001:41d0:303:412a::1 Sep 06 07:56:12 volumio ntpd[780]: Soliciting pool server 212.227.232.161 Sep 06 07:56:13 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Sep 06 07:56:13 volumio ntpd[780]: Soliciting pool server 77.197.121.128 Sep 06 07:56:14 volumio ntpd[780]: receive: Unexpected origin timestamp 0xec664b7d.c0fc5208 does not match aorg 0000000000.00000000 from server@109.190.177.203 xmt 0xec664b7e.cf969580 Sep 06 07:56:14 volumio ntpd[780]: receive: Unexpected origin timestamp 0xec664b7d.c0f9eda3 does not match aorg 0000000000.00000000 from server@82.66.156.239 xmt 0xec664b7e.c3483e60 Sep 06 07:56:14 volumio ntpd[780]: receive: Unexpected origin timestamp 0xec664b7d.c0f72f8f does not match aorg 0000000000.00000000 from server@82.64.131.93 xmt 0xec664b7e.cfd6cbd0 Sep 06 07:56:14 volumio ntpd[780]: receive: Unexpected origin timestamp 0xec664b7d.c0ebe7e1 does not match aorg 0000000000.00000000 from server@212.227.232.161 xmt 0xec664b7e.d1823b5a Sep 06 07:56:14 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetVisibleSources Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:15 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetQueue Sep 06 07:56:15 volumio volumio[957]: info: CoreStateMachine::getQueue Sep 06 07:56:15 volumio volumio[957]: info: CorePlayQueue::getQueue Sep 06 07:56:15 volumio volumio[957]: info: Listing playlists Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Sep 06 07:56:15 volumio volumio[957]: info: Received Get System Info Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 07:56:15 volumio volumio[957]: info: Discovery: Getting this device information Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:15 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:15 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 07:56:15 volumio volumio[957]: info: Received Get System Info Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 07:56:15 volumio volumio[957]: info: Discovery: Getting this device information Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:15 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:15 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 07:56:15 volumio ntpd[780]: Soliciting pool server 62.210.136.236 Sep 06 07:56:16 volumio volumio[957]: error: MyVolumio Plugin failed to authenticate in a timely fashion Sep 06 07:56:16 volumio volumio[957]: info: Completed starting MyVolumio Plugin Sep 06 07:56:16 volumio volumio[957]: [Metrics] CommandRouter: 54s 226.80ms Sep 06 07:56:16 volumio volumio[957]: info: CoreCommandRouter::volumiosetStartupVolume Sep 06 07:56:16 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:56:16 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:16 volumio volumio[957]: info: CoreCommandRouter::Close All Modals sent Sep 06 07:56:16 volumio volumio[957]: info: CoreCommandRouter::Close All Modals sent Sep 06 07:56:17 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Sep 06 07:56:17 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:56:17 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Sep 06 07:56:18 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Sep 06 07:56:20 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 06 07:56:21 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 07:56:21 volumio volumio[957]: info: Received Get System Info Sep 06 07:56:21 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 07:56:21 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 07:56:21 volumio volumio[957]: info: Discovery: Getting this device information Sep 06 07:56:21 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:21 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:21 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Sep 06 07:56:23 volumio volumio[957]: info: Received Get System Info Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 07:56:23 volumio volumio[957]: info: Discovery: Getting this device information Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:23 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 07:56:23 volumio volumio[957]: info: BOOT COMPLETED Sep 06 07:56:25 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Sep 06 07:56:27 volumio volumio[1367]: ...................................................................................................................................................................++++ Sep 06 07:56:27 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Sep 06 07:56:31 volumio volumio[957]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Sep 06 07:56:31 volumio volumio[957]: info: Received Get System Version Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Sep 06 07:56:31 volumio volumio[957]: info: Received Get System Info Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 06 07:56:31 volumio volumio[957]: info: Discovery: Getting this device information Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:31 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:31 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 06 07:56:48 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 06 07:56:58 volumio volumio[957]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Sep 06 07:56:58 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Sep 06 07:56:58 volumio volumio[957]: info: Preparing to save Alsa Options, stopping services first Sep 06 07:56:58 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:56:58 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:58 volumio volumio[957]: info: CoreCommandRouter::volumioPause Sep 06 07:56:58 volumio volumio[957]: info: CoreStateMachine::pause Sep 06 07:56:58 volumio volumio[957]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Sep 06 07:56:58 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:56:59 volumio volumio[957]: info: Found match in Cards Database: setting mixer PCM for card Headphones Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 06 07:56:59 volumio volumio[957]: info: Updating Volume Controller Parameters: Device: 0 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 06 07:56:59 volumio volumio[957]: info: Disabling external Volume Control Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 07:56:59 volumio volumio[957]: info: Preparing to generate the ALSA configuration file Sep 06 07:56:59 volumio volumio[957]: info: Asound.conf file unchanged, so no further update is needed Sep 06 07:56:59 volumio volumio[957]: info: Output device has changed, restarting MPD Sep 06 07:56:59 volumio volumio[957]: info: Output device has changed, restarting Shairport Sync Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 06 07:56:59 volumio sudo[2001]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 06 07:56:59 volumio sudo[2003]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 06 07:56:59 volumio sudo[2001]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:56:59 volumio sudo[2003]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:56:59 volumio sudo[2001]: pam_unix(sudo:session): session closed for user root Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:56:59 volumio systemd[1]: Stopping Music Player Daemon... Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 06 07:56:59 volumio volumio[957]: info: MPD Permissions set Sep 06 07:56:59 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:56:59 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:56:59 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:56:59 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:00 volumio systemd[1]: mpd.service: Succeeded. Sep 06 07:57:00 volumio systemd[1]: Stopped Music Player Daemon. Sep 06 07:57:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:57:00 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:00 volumio volumio[957]: info: Starting Shairport Sync Sep 06 07:57:00 volumio systemd[1]: Starting Music Player Daemon... Sep 06 07:57:00 volumio sudo[2033]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 06 07:57:00 volumio sudo[2033]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 06 07:57:00 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 06 07:57:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 06 07:57:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 06 07:57:00 volumio sudo[2033]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:00 volumio volumio[957]: info: Shairport-Sync Started Sep 06 07:57:00 volumio sudo[2031]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 06 07:57:00 volumio sudo[2031]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:00 volumio sudo[2031]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:02 volumio volumio[1367]: ...................................................................................................................................++++ Sep 06 07:57:02 volumio volumio[1367]: e is 65537 (0x010001) Sep 06 07:57:02 volumio volumio[1367]: writing RSA key Sep 06 07:57:03 volumio volumio[957]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Sep 06 07:57:03 volumio volumio[957]: info: CoreStateMachine::getcurrentVolume Sep 06 07:57:03 volumio volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Sep 06 07:57:03 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:57:03 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:57:03 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:03 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:03 volumio volumio[957]: info: CoreStateMachine::updateTrackBlock Sep 06 07:57:03 volumio volumio[957]: info: CorePlayQueue::getTrackBlock Sep 06 07:57:03 volumio volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Sep 06 07:57:03 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:57:03 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:57:03 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:03 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:04 volumio volumio[957]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Sep 06 07:57:04 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Sep 06 07:57:04 volumio volumio[957]: info: Preparing to save Alsa Options, stopping services first Sep 06 07:57:04 volumio volumio[957]: info: CoreCommandRouter::volumioGetState Sep 06 07:57:04 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:04 volumio volumio[957]: info: CoreCommandRouter::volumioPause Sep 06 07:57:04 volumio volumio[957]: info: CoreStateMachine::pause Sep 06 07:57:04 volumio volumio[957]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} Sep 06 07:57:04 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:57:04 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:57:04 volumio volumio[957]: info: Found match in Cards Database: setting mixer PCM for card Headphones Sep 06 07:57:05 volumio mpd[2039]: Sep 06 07:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 06 07:57:05 volumio systemd[1]: Started Music Player Daemon. Sep 06 07:57:05 volumio sudo[2003]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::volumioUpdateVolumeSettings Sep 06 07:57:05 volumio volumio[957]: info: Updating Volume Controller Parameters: Device: 0 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Sep 06 07:57:05 volumio volumio[957]: info: Disabling external Volume Control Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::getUIConfigOnPlugin Sep 06 07:57:05 volumio volumio[957]: info: Preparing to generate the ALSA configuration file Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Sep 06 07:57:05 volumio volumio[957]: info: Asound.conf file unchanged, so no further update is needed Sep 06 07:57:05 volumio volumio[957]: info: Output device has changed, restarting MPD Sep 06 07:57:05 volumio sudo[2144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Sep 06 07:57:05 volumio volumio[957]: info: Output device has changed, restarting Shairport Sync Sep 06 07:57:05 volumio sudo[2144]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:57:05 volumio sudo[2144]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:05 volumio sudo[2151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Sep 06 07:57:05 volumio sudo[2151]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:05 volumio systemd[1]: Stopping Music Player Daemon... Sep 06 07:57:05 volumio volumio[957]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Sep 06 07:57:05 volumio volumio[957]: error: updateQueue error: null Sep 06 07:57:05 volumio systemd[1]: mpd.service: Succeeded. Sep 06 07:57:05 volumio volumio[957]: info: MPD Permissions set Sep 06 07:57:05 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:57:05 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:57:05 volumio systemd[1]: Stopped Music Player Daemon. Sep 06 07:57:05 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:05 volumio systemd[1]: Starting Music Player Daemon... Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Sep 06 07:57:05 volumio volumio[957]: info: Starting Shairport Sync Sep 06 07:57:06 volumio sudo[2163]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 06 07:57:06 volumio sudo[2163]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:06 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Sep 06 07:57:06 volumio systemd[1]: shairport-sync.service: Succeeded. Sep 06 07:57:06 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Sep 06 07:57:06 volumio sudo[2157]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Sep 06 07:57:06 volumio sudo[2157]: pam_unix(sudo:session): session opened for user root by (uid=0) Sep 06 07:57:06 volumio sudo[2157]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:06 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Sep 06 07:57:06 volumio sudo[2163]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:06 volumio volumio[957]: info: Shairport-Sync Started Sep 06 07:57:08 volumio mpd[2167]: Sep 06 07:57 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Sep 06 07:57:08 volumio systemd[1]: Started Music Player Daemon. Sep 06 07:57:08 volumio sudo[2151]: pam_unix(sudo:session): session closed for user root Sep 06 07:57:08 volumio volumio[957]: error: updateQueue error: null Sep 06 07:57:09 volumio volumio[957]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Sep 06 07:57:09 volumio volumio[957]: info: CoreStateMachine::getcurrentVolume Sep 06 07:57:09 volumio volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Sep 06 07:57:09 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:57:09 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:57:09 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:09 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:09 volumio volumio[957]: info: CoreStateMachine::updateTrackBlock Sep 06 07:57:09 volumio volumio[957]: info: CorePlayQueue::getTrackBlock Sep 06 07:57:09 volumio volumio[957]: info: CoreCommandRouter::volumioRetrievevolume Sep 06 07:57:09 volumio volumio[957]: info: VolumeController:: Volume=86 Mute =false Sep 06 07:57:09 volumio volumio[957]: info: CoreStateMachine::pushState Sep 06 07:57:09 volumio volumio[957]: info: CorePlayQueue::getTrack 0 Sep 06 07:57:09 volumio volumio[957]: info: CoreCommandRouter::volumioPushState Sep 06 07:57:23 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 06 07:57:24 volumio volumio[957]: info: Preload queue cleared Sep 06 07:57:28 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 06 07:57:28 volumio volumio[957]: info: Preload queue cleared Sep 06 07:57:33 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 06 07:57:33 volumio volumio[957]: info: Preload queue cleared Sep 06 07:57:35 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 06 07:57:35 volumio volumio[957]: info: Preload queue cleared Sep 06 07:57:37 volumio volumio[957]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Sep 06 07:57:37 volumio volumio[957]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 07:57:37 volumio volumio[957]: TypeError: Cannot read property 'length' of undefined Sep 06 07:57:37 volumio volumio[957]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Sep 06 07:57:37 volumio volumio[957]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Sep 06 07:57:37 volumio volumio[957]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Sep 06 07:57:37 volumio volumio[957]: at Parser.emit (events.js:315:20) Sep 06 07:57:37 volumio volumio[957]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Sep 06 07:57:37 volumio volumio[957]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Sep 06 07:57:37 volumio volumio[957]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Sep 06 07:57:37 volumio volumio[957]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Sep 06 07:57:37 volumio volumio[957]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Sep 06 07:57:37 volumio volumio[957]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Sep 06 07:57:37 volumio volumio[957]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Sep 06 07:57:37 volumio volumio[957]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Sep 06 07:57:37 volumio volumio[957]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Sep 06 07:57:37 volumio volumio[957]: at IncomingMessage.emit (events.js:327:22) Sep 06 07:57:37 volumio volumio[957]: at endReadableNT (internal/streams/readable.js:1327:12) Sep 06 07:57:37 volumio volumio[957]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Sep 06 07:57:37 volumio volumio[957]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 06 07:57:39 volumio sudo[2238]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-06 07:56 Sep 06 07:57:39 volumio sudo[2238]: 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="29866754e5f1d7e4d0f581c10d9f22852f6f21db" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 26 Jul 2025 10:25:36 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cf6e14681b2ecbbdc9a62186b0f3114c"