-- Logs begin at Thu 2019-02-14 10:11:58 GMT, end at Fri 2024-10-11 15:15:18 BST. -- Oct 11 15:14:02 pi5k6.6 volumio[1300]: error: MyVolumio Plugins failed to start in a timely fashion Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: BOOT COMPLETED Oct 11 15:14:02 pi5k6.6 volumio[1300]: [Metrics] CommandRouter: 42s 928.13ms Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumiosetStartupVolume Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: VolumeController:: Setting startup Volume 50 Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: VolumeController::SetAlsaVolume50 Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::Close All Modals sent Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::Close All Modals sent Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreStateMachine::pushState Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioPushState Oct 11 15:14:02 pi5k6.6 volumio[1300]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Oct 11 15:14:02 pi5k6.6 volumio[1300]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Oct 11 15:14:02 pi5k6.6 volumio[1300]: aplay: main:828: audio open error: Unknown error 524 Oct 11 15:14:03 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 11 15:14:03 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 15:14:03 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 11 15:14:10 pi5k6.6 sudo[2209]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 15:14:10 pi5k6.6 sudo[2209]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:14:10 pi5k6.6 sudo[2209]: pam_unix(sudo:session): session closed for user root Oct 11 15:14:10 pi5k6.6 sudo[2211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 15:14:10 pi5k6.6 sudo[2211]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:14:10 pi5k6.6 sudo[2211]: pam_unix(sudo:session): session closed for user root Oct 11 15:14:10 pi5k6.6 volumio[1300]: verbose: New Socket.io Connection to 192.168.30.210 from 192.168.30.10 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:131.0) Gecko/20100101 Firefox/131.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetVisibleSources Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: Received Get System Info Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: Discovery: Getting this device information Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: Listing playlists Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 15:14:10 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 11 15:14:11 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:11 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: Received Get System Info Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: Discovery: Getting this device information Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:12 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: Received Get System Info Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: Discovery: Getting this device information Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 15:14:13 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 15:14:20 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 11 15:14:21 pi5k6.6 ntpd[1208]: Soliciting pool server 162.159.200.1 Oct 11 15:14:22 pi5k6.6 ntpd[1208]: Soliciting pool server 139.143.5.31 Oct 11 15:14:23 pi5k6.6 ntpd[1208]: Soliciting pool server 162.159.200.123 Oct 11 15:14:23 pi5k6.6 ntpd[1208]: Soliciting pool server 195.171.43.10 Oct 11 15:14:24 pi5k6.6 ntpd[1208]: Soliciting pool server 178.62.18.76 Oct 11 15:14:24 pi5k6.6 ntpd[1208]: Soliciting pool server 176.58.109.199 Oct 11 15:14:24 pi5k6.6 ntpd[1208]: Soliciting pool server 63.135.73.82 Oct 11 15:14:24 pi5k6.6 ntpd[1208]: Soliciting pool server 88.80.189.24 Oct 11 15:14:24 pi5k6.6 ntpd[1208]: Soliciting pool server 85.199.214.101 Oct 11 15:14:25 pi5k6.6 ntpd[1208]: Soliciting pool server 82.219.4.30 Oct 11 15:14:25 pi5k6.6 ntpd[1208]: Soliciting pool server 185.53.45.5 Oct 11 15:14:25 pi5k6.6 ntpd[1208]: Soliciting pool server 64:ff9b::a29f:c801 Oct 11 15:14:25 pi5k6.6 ntpd[1208]: Soliciting pool server 90.155.73.34 Oct 11 15:14:26 pi5k6.6 ntpd[1208]: Soliciting pool server 51.155.213.242 Oct 11 15:14:26 pi5k6.6 ntpd[1208]: Soliciting pool server 131.111.8.63 Oct 11 15:14:26 pi5k6.6 ntpd[1208]: Soliciting pool server 64:ff9b::b2d7:e418 Oct 11 15:14:27 pi5k6.6 ntpd[1208]: Soliciting pool server 44.31.52.36 Oct 11 15:14:27 pi5k6.6 ntpd[1208]: Soliciting pool server 2603:c020:c00a:c00:195:242:99:71 Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: Received Get System Version Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: Received Get System Info Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: Discovery: Getting this device information Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:14:28 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 15:14:28 pi5k6.6 ntpd[1208]: Soliciting pool server 64:ff9b::81fa:23fa Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b44e693 does not match aorg 0000000000.00000000 from server@88.80.189.24 xmt 0xeab3b173.d91b3d46 Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b439849 does not match aorg 0000000000.00000000 from server@85.199.214.101 xmt 0xeab3b173.d978625d Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b42ffe5 does not match aorg 0000000000.00000000 from server@131.111.8.63 xmt 0xeab3b173.d9d8062c Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b408d56 does not match aorg 0000000000.00000000 from server@44.31.52.36 xmt 0xeab3b173.d9485b12 Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b443f8d does not match aorg 0000000000.00000000 from server@63.135.73.82 xmt 0xeab3b173.d926b560 Oct 11 15:15:15 pi5k6.6 ntpd[1208]: receive: Unexpected origin timestamp 0xeab3b145.9b425670 does not match aorg 0000000000.00000000 from server@51.155.213.242 xmt 0xeab3b173.dac02b1a Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Preparing to save Alsa Options, stopping services first Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioGetState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioPause Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreStateMachine::pause Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Saving Audio Output to: {"output_device":{"value":"0","label":"HDMI 0 Out"},"i2s":true,"i2sid":{"value":"generic-dac","label":"Generic I2S DAC"}} Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Enabling I2S DAC: Generic I2S DAC Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , enableI2SDAC Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 sudo[2260]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay -l Oct 11 15:15:16 pi5k6.6 sudo[2260]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 sudo[2260]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: No Overlays Loaded Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SAlsaName Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 sudo[2263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/dtoverlay hifiberry-dac Oct 11 15:15:16 pi5k6.6 sudo[2263]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /axi/pcie@120000/rp1/i2s@a0000/status Oct 11 15:15:16 pi5k6.6 kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/compatible Oct 11 15:15:16 pi5k6.6 kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/i2s-controller Oct 11 15:15:16 pi5k6.6 kernel: OF: overlay: WARNING: memory leak will occur if overlay removed, property: /soc/sound/status Oct 11 15:15:16 pi5k6.6 sudo[2263]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: warn: Unable to locate the device HDMI 0 Out a reboot may be required. Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SMixer Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Setting default mixerSoftMaster for Softvolume device Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Disabling external Volume Control Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Enable softmixer device for audio device undefined Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: wizard , setWizardAction Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: I2S Param [object Object] successfully enabled Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Software Volume ALSA configuration written Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Preparing to generate the ALSA configuration file Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Getting Alsa Cards List without I2S DAC Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Reading ALSA contributions from plugins. Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreStateMachine::pushState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioPushState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Asound.conf file written Oct 11 15:15:16 pi5k6.6 sudo[2303]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 11 15:15:16 pi5k6.6 sudo[2303]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 sudo[2303]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Output device has changed, restarting MPD Oct 11 15:15:16 pi5k6.6 sudo[2308]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 15:15:16 pi5k6.6 sudo[2308]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Output device has changed, restarting Shairport Sync Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 sudo[2308]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 sudo[2311]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 15:15:16 pi5k6.6 sudo[2311]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 systemd[1]: Stopping Music Player Daemon... Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Output device has changed, restarting MPD Oct 11 15:15:16 pi5k6.6 systemd[1]: mpd.service: Succeeded. Oct 11 15:15:16 pi5k6.6 systemd[1]: Stopped Music Player Daemon. Oct 11 15:15:16 pi5k6.6 sudo[2318]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 15:15:16 pi5k6.6 sudo[2318]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Output device has changed, restarting Shairport Sync Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 sudo[2318]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 sudo[2321]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 15:15:16 pi5k6.6 systemd[1]: Starting Music Player Daemon... Oct 11 15:15:16 pi5k6.6 sudo[2321]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 11 15:15:16 pi5k6.6 systemd[1]: mpd.service: Succeeded. Oct 11 15:15:16 pi5k6.6 systemd[1]: Stopped Music Player Daemon. Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 15:15:16 pi5k6.6 systemd[1]: Starting Music Player Daemon... Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: MPD Permissions set Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: MPD Permissions set Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 15:15:16 pi5k6.6 sudo[2326]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 15:15:16 pi5k6.6 sudo[2326]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Starting Shairport Sync Oct 11 15:15:16 pi5k6.6 sudo[2326]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Starting Shairport Sync Oct 11 15:15:16 pi5k6.6 sudo[2338]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 15:15:16 pi5k6.6 sudo[2338]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 sudo[2341]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 15:15:16 pi5k6.6 sudo[2341]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: VolumeController::SetAlsaVolume0 Oct 11 15:15:16 pi5k6.6 systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 11 15:15:16 pi5k6.6 systemd[1]: shairport-sync.service: Succeeded. Oct 11 15:15:16 pi5k6.6 systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreStateMachine::pushState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioPushState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: VolumeController::SetAlsaVolume0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreStateMachine::pushState Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CorePlayQueue::getTrack 0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: CoreCommandRouter::volumioPushState Oct 11 15:15:16 pi5k6.6 systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 11 15:15:16 pi5k6.6 sudo[2341]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 sudo[2338]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Oct 11 15:15:16 pi5k6.6 volumio[1300]: info: Shairport-Sync Started Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control 'SoftMaster',0 Oct 11 15:15:16 pi5k6.6 mpd[2337]: Oct 11 15:15 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 11 15:15:16 pi5k6.6 systemd[1]: Started Music Player Daemon. Oct 11 15:15:16 pi5k6.6 sudo[2311]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 sudo[2321]: pam_unix(sudo:session): session closed for user root Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: MPD error: The expression evaluated to a falsy value: Oct 11 15:15:16 pi5k6.6 volumio[1300]: assert.ok(self.idling) Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: The expression evaluated to a falsy value: Oct 11 15:15:16 pi5k6.6 volumio[1300]: assert.ok(self.idling) Oct 11 15:15:16 pi5k6.6 volumio[1300]: error: updateQueue error: null Oct 11 15:15:18 pi5k6.6 volumio[1300]: info: ___________ PLUGINS: Run onVolumioReboot Tasks ___________ Oct 11 15:15:18 pi5k6.6 volumio[1300]: info: PLUGIN onReboot : networkfs Oct 11 15:15:18 pi5k6.6 volumio[1300]: info: PLUGIN onReboot : audiophonicsonoff Oct 11 15:15:18 pi5k6.6 volumio[1300]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 15:15:18 pi5k6.6 volumio[1300]: TypeError: Cannot read property 'writeSync' of undefined Oct 11 15:15:18 pi5k6.6 volumio[1300]: at ControllerAudiophonicsOnOff.onVolumioReboot (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at PluginManager.onVolumioRebootPlugin (/volumio/app/pluginmanager.js:684:30) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at HashMap. (/volumio/app/pluginmanager.js:668:31) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at PluginManager.onVolumioReboot (/volumio/app/pluginmanager.js:666:20) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at CoreCommandRouter.reboot (/volumio/app/index.js:1331:22) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:864:33) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at Socket.emit (events.js:315:20) Oct 11 15:15:18 pi5k6.6 volumio[1300]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Oct 11 15:15:18 pi5k6.6 volumio[1300]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 11 15:15:18 pi5k6.6 volumio[1300]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 15:15:18 pi5k6.6 sudo[2359]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-11 15:14 Oct 11 15:15:18 pi5k6.6 sudo[2359]: 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="99ba0a37c11b93215dc3e0ee3c22f0c0313c225b" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8ef80245b1f7b577b29fe08b77efdc88d53369e5" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 11 Oct 2024 10:54:46 AM CEST" VOLUMIO_VERSION="3.759" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="a1641e68e16692da54c105ebfa2aa2be"