-- Logs begin at Fri 2024-10-11 12:18:51 BST, end at Fri 2024-10-11 12:23:33 BST. -- Oct 11 12:22:03 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:07 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:11 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:13 hifi kernel: usb 3-1.1: USB disconnect, device number 3 Oct 11 12:22:13 hifi volumio[1045]: info: Oct 11 12:22:13 hifi volumio[1045]: ---------------------------- USB Audio Device Detached Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Oct 11 12:22:13 hifi kernel: usb 3-1.1: new high-speed USB device number 4 using ehci-pci Oct 11 12:22:13 hifi kernel: usb 3-1.1: New USB device found, idVendor=152a, idProduct=8750, bcdDevice= 1.08 Oct 11 12:22:13 hifi kernel: usb 3-1.1: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Oct 11 12:22:13 hifi kernel: usb 3-1.1: Product: E30 Oct 11 12:22:13 hifi kernel: usb 3-1.1: Manufacturer: Topping Oct 11 12:22:13 hifi kernel: usb 3-1.1: 1:3 : unsupported format bits 0x100000000 Oct 11 12:22:13 hifi volumio[1045]: info: Oct 11 12:22:13 hifi volumio[1045]: ---------------------------- USB Audio Device Attached Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::Close All Modals sent Oct 11 12:22:13 hifi volumio[1045]: info: Preparing to save Alsa Options, stopping services first Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::volumioPause Oct 11 12:22:13 hifi volumio[1045]: info: CoreStateMachine::pause Oct 11 12:22:13 hifi volumio[1045]: info: CoreStateMachine::stPlaybackTimer Oct 11 12:22:13 hifi volumio[1045]: info: CoreStateMachine::servicePause Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::servicePause Oct 11 12:22:13 hifi volumio[1045]: info: Airplay Pause with DBUS Call Oct 11 12:22:13 hifi volumio[1045]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"E30","alsacard":"E30"},"i2s":false} Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:22:13 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:22:14 hifi volumio[1045]: info: Setting mixer E30 for card E30 Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 11 12:22:14 hifi volumio[1045]: info: Updating Volume Controller Parameters: Device: 5 Name: E30 Mixer: E30 Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 11 12:22:14 hifi volumio[1045]: info: Disabling external Volume Control Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:22:14 hifi volumio[1045]: info: Preparing to generate the ALSA configuration file Oct 11 12:22:14 hifi volumio[1045]: info: Error Airplay DBUS Call Pause: Error: Command failed: /usr/bin/dbus-send --system --print-reply --type=method_call --dest=org.gnome.ShairportSync '/org/gnome/ShairportSync' org.gnome.ShairportSync.RemoteControl.Pause Oct 11 12:22:14 hifi volumio[1045]: Error org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.ShairportSync was not provided by any .service files Oct 11 12:22:14 hifi volumio[1045]: info: Asound.conf file unchanged, so no further update is needed Oct 11 12:22:14 hifi volumio[1045]: info: Output device has changed, restarting MPD Oct 11 12:22:14 hifi sudo[1973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 12:22:14 hifi sudo[1973]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:22:14 hifi sudo[1973]: pam_unix(sudo:session): session closed for user root Oct 11 12:22:14 hifi volumio[1045]: info: Output device has changed, restarting Shairport Sync Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:22:14 hifi sudo[1976]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 12:22:14 hifi sudo[1976]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:22:14 hifi systemd[1]: Stopping Music Player Daemon... Oct 11 12:22:14 hifi volumio[1045]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:22:14 hifi systemd[1]: mpd.service: Succeeded. Oct 11 12:22:14 hifi systemd[1]: Stopped Music Player Daemon. Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 12:22:14 hifi systemd[1]: Starting Music Player Daemon... Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 12:22:14 hifi volumio[1045]: info: MPD Permissions set Oct 11 12:22:14 hifi volumio[1045]: info: VolumeController:: Volume=0 Mute =false Oct 11 12:22:14 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:22:14 hifi volumio[1045]: info: Starting Shairport Sync Oct 11 12:22:14 hifi sudo[1986]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 12:22:14 hifi sudo[1986]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:22:14 hifi sudo[1986]: pam_unix(sudo:session): session closed for user root Oct 11 12:22:14 hifi sudo[1996]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 12:22:14 hifi sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:22:14 hifi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 11 12:22:14 hifi shairport-sync[1513]: {"time":1728645660049,"response":"startAirplayPlayback Success"} Oct 11 12:22:14 hifi systemd[1]: shairport-sync.service: Succeeded. Oct 11 12:22:14 hifi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 11 12:22:14 hifi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 11 12:22:14 hifi sudo[1996]: pam_unix(sudo:session): session closed for user root Oct 11 12:22:14 hifi volumio[1045]: info: Shairport-Sync Started Oct 11 12:22:14 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Oct 11 12:22:14 hifi mpd[1995]: Oct 11 11:22 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 11 12:22:14 hifi systemd[1]: Started Music Player Daemon. Oct 11 12:22:14 hifi sudo[1976]: pam_unix(sudo:session): session closed for user root Oct 11 12:22:14 hifi volumio[1045]: error: updateQueue error: null Oct 11 12:22:15 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:15 hifi kernel: usb 3-1.1: USB disconnect, device number 4 Oct 11 12:22:15 hifi volumio[1045]: info: Oct 11 12:22:15 hifi volumio[1045]: ---------------------------- USB Audio Device Detached Oct 11 12:22:15 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Oct 11 12:22:15 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:22:15 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Oct 11 12:22:16 hifi kernel: usb 3-1.1: new high-speed USB device number 5 using ehci-pci Oct 11 12:22:16 hifi kernel: usb 3-1.1: device not accepting address 5, error -71 Oct 11 12:22:17 hifi kernel: usb 3-1.1: new high-speed USB device number 6 using ehci-pci Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 11 12:22:18 hifi volumio[1045]: info: CoreStateMachine::getcurrentVolume Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrievevolume Oct 11 12:22:18 hifi volumio[1045]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Oct 11 12:22:18 hifi volumio[1045]: info: VolumeController:: Volume=undefined Mute =false Oct 11 12:22:18 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:22:18 hifi volumio[1045]: info: CoreStateMachine::updateTrackBlock Oct 11 12:22:18 hifi volumio[1045]: info: CorePlayQueue::getTrackBlock Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrievevolume Oct 11 12:22:18 hifi volumio[1045]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Oct 11 12:22:18 hifi volumio[1045]: info: VolumeController:: Volume=undefined Mute =false Oct 11 12:22:18 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:22:18 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:22:18 hifi kernel: usb 3-1-port1: Cannot enable. Maybe the USB cable is bad? Oct 11 12:22:18 hifi kernel: usb 3-1-port1: attempt power cycle Oct 11 12:22:19 hifi kernel: usb 3-1.1: new high-speed USB device number 7 using ehci-pci Oct 11 12:22:19 hifi kernel: usb 3-1.1: device descriptor read/8, error -71 Oct 11 12:22:19 hifi kernel: usb 3-1.1: device descriptor read/8, error -71 Oct 11 12:22:19 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:19 hifi kernel: usb 3-1.1: new high-speed USB device number 8 using ehci-pci Oct 11 12:22:19 hifi kernel: usb 3-1.1: device descriptor read/8, error -71 Oct 11 12:22:19 hifi kernel: usb 3-1.1: device descriptor read/8, error -71 Oct 11 12:22:20 hifi kernel: usb 3-1-port1: unable to enumerate USB device Oct 11 12:22:23 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:27 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:27 hifi go-librespot[1493]: time="2024-10-11T11:22:27Z" level=debug msg="handling transfer player command from f260a6a62af9b4d38bb512d122cd7c167381bef5" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=trace msg="fetched new page 0 with 114 items (list: 114)" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="loading track spotify:track:1Atex0qFqPysiRWifg9eb5 (paused: false, position: 95133ms)" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=trace msg="emitting websocket event: will_play" Oct 11 12:22:28 hifi volumio[1045]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1Atex0qFqPysiRWifg9eb5","play_origin":"playlist"}} Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1Atex0qFqPysiRWifg9eb5" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="requested aes key for file c4ac6bc9bbaabead25a851929e3758f61a454cb5, gid: 1Atex0qFqPysiRWifg9eb5" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="fetched first chunk of 9, total size is 4701721 bytes" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="fetched chunk 3/8, size: 524288" Oct 11 12:22:28 hifi go-librespot[1493]: time="2024-10-11T11:22:28Z" level=debug msg="fetched chunk 1/8, size: 524288" Oct 11 12:22:29 hifi go-librespot[1493]: time="2024-10-11T11:22:29Z" level=debug msg="fetched chunk 8/8, size: 507417" Oct 11 12:22:29 hifi go-librespot[1493]: time="2024-10-11T11:22:29Z" level=debug msg="fetched chunk 2/8, size: 524288" Oct 11 12:22:29 hifi go-librespot[1493]: time="2024-10-11T11:22:29Z" level=debug msg="fetched chunk 7/8, size: 524288" Oct 11 12:22:29 hifi go-librespot[1493]: time="2024-10-11T11:22:29Z" level=trace msg="seek to 95133ms (diff: 97ms, samples: 4195365, bytes: 3752493)" Oct 11 12:22:29 hifi go-librespot[1493]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 11 12:22:29 hifi go-librespot[1493]: time="2024-10-11T11:22:29Z" level=warning msg="failed handling dealer request" error="failed loading current track (transfer): failed creating stream: ALSA error at snd_pcm_open: No such device" Oct 11 12:22:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=debug msg="handling transfer player command from f260a6a62af9b4d38bb512d122cd7c167381bef5" Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=trace msg="fetched new page 0 with 114 items (list: 114)" Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=debug msg="loading track spotify:track:1Atex0qFqPysiRWifg9eb5 (paused: false, position: 99466ms)" Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=trace msg="emitting websocket event: will_play" Oct 11 12:22:32 hifi volumio[1045]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1Atex0qFqPysiRWifg9eb5","play_origin":"playlist"}} Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:1Atex0qFqPysiRWifg9eb5" Oct 11 12:22:32 hifi go-librespot[1493]: time="2024-10-11T11:22:32Z" level=debug msg="requested aes key for file c4ac6bc9bbaabead25a851929e3758f61a454cb5, gid: 1Atex0qFqPysiRWifg9eb5" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched first chunk of 9, total size is 4701721 bytes" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched chunk 3/8, size: 524288" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched chunk 7/8, size: 524288" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=trace msg="seek to 99466ms (diff: 107ms, samples: 4386450, bytes: 3926796)" Oct 11 12:22:33 hifi go-librespot[1493]: ALSA lib pcm_hw.c:1822:(_snd_pcm_hw_open) Invalid value for card Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=warning msg="failed handling dealer request" error="failed loading current track (transfer): failed creating stream: ALSA error at snd_pcm_open: No such device" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched chunk 2/8, size: 524288" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched chunk 8/8, size: 507417" Oct 11 12:22:33 hifi go-librespot[1493]: time="2024-10-11T11:22:33Z" level=debug msg="fetched chunk 1/8, size: 524288" Oct 11 12:22:35 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , rescanDb Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::sendMpdCommand rescan Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Oct 11 12:22:37 hifi volumio[1045]: info: Oct 11 12:22:37 hifi volumio[1045]: ---------------------------- MPD announces state update: update Oct 11 12:22:37 hifi volumio[1045]: info: sendMpdCommand rescan took 3 milliseconds Oct 11 12:22:37 hifi volumio[1045]: info: ControllerMpd::getState Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Oct 11 12:22:37 hifi volumio[1045]: info: sendMpdCommand status took 7 milliseconds Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::parseState Oct 11 12:22:37 hifi volumio[1045]: info: Command Router : Notfying DB Updatetrue Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Oct 11 12:22:37 hifi volumio[1045]: info: Oct 11 12:22:37 hifi volumio[1045]: ---------------------------- MPD announces state update: update Oct 11 12:22:37 hifi volumio[1045]: info: sendMpdCommand status took 238 milliseconds Oct 11 12:22:37 hifi volumio[1045]: info: ControllerMpd::getState Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::sendMpdCommand status Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::parseState Oct 11 12:22:37 hifi volumio[1045]: info: ControllerMpd::pushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::servicePushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:22:37 hifi volumio[1045]: info: CorePlayQueue::getTrack 0 Oct 11 12:22:37 hifi volumio[1045]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Oct 11 12:22:37 hifi volumio[1045]: info: ------------------------------ 255ms Oct 11 12:22:37 hifi volumio[1045]: info: sendMpdCommand status took 15 milliseconds Oct 11 12:22:37 hifi volumio[1045]: info: sendMpdCommand status took 15 milliseconds Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::parseState Oct 11 12:22:37 hifi volumio[1045]: info: Command Router : Notfying DB Updatefalse Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::Close All Modals sent Oct 11 12:22:37 hifi volumio[1045]: verbose: ControllerMpd::parseState Oct 11 12:22:37 hifi volumio[1045]: info: ControllerMpd::pushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::servicePushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:22:37 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:22:37 hifi volumio[1045]: info: CorePlayQueue::getTrack 0 Oct 11 12:22:37 hifi volumio[1045]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current spop Received mpd Oct 11 12:22:37 hifi volumio[1045]: info: ------------------------------ 78ms Oct 11 12:22:39 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 11 12:22:41 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 11 12:22:45 hifi volumio[1045]: info: Received Get System Version Oct 11 12:22:45 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 11 12:22:50 hifi volumio-remote-updater[680]: No test mode Oct 11 12:22:50 hifi volumio-remote-updater[680]: No alpha test mode Oct 11 12:22:50 hifi volumio[1045]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 11 12:22:50 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 11 12:22:52 hifi volumio[1045]: info: CoreCommandRouter::Close All Modals sent Oct 11 12:22:52 hifi go-librespot[1493]: time="2024-10-11T11:22:52Z" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 11 12:22:52 hifi go-librespot[1493]: time="2024-10-11T11:22:52Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 350" Oct 11 12:22:52 hifi go-librespot[1493]: time="2024-10-11T11:22:52Z" level=debug msg="put connect state inactive" Oct 11 12:22:52 hifi go-librespot[1493]: time="2024-10-11T11:22:52Z" level=trace msg="emitting websocket event: inactive" Oct 11 12:22:52 hifi volumio[1045]: SPOTIFY: received: {"type":"inactive","data":null} Oct 11 12:22:52 hifi volumio[1045]: error: Failed to decode event: inactive Oct 11 12:23:16 hifi kernel: usb 3-1.1: new high-speed USB device number 9 using ehci-pci Oct 11 12:23:16 hifi kernel: usb 3-1.1: New USB device found, idVendor=152a, idProduct=8750, bcdDevice= 1.08 Oct 11 12:23:16 hifi kernel: usb 3-1.1: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Oct 11 12:23:16 hifi kernel: usb 3-1.1: Product: E30 Oct 11 12:23:16 hifi kernel: usb 3-1.1: Manufacturer: Topping Oct 11 12:23:16 hifi kernel: usb 3-1.1: 1:3 : unsupported format bits 0x100000000 Oct 11 12:23:16 hifi volumio[1045]: info: Oct 11 12:23:16 hifi volumio[1045]: ---------------------------- USB Audio Device Attached Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::Close All Modals sent Oct 11 12:23:16 hifi volumio[1045]: info: Preparing to save Alsa Options, stopping services first Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::volumioPause Oct 11 12:23:16 hifi volumio[1045]: info: CoreStateMachine::pause Oct 11 12:23:16 hifi volumio[1045]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"E30","alsacard":"E30"},"i2s":false} Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:23:16 hifi volumio[1045]: info: Setting mixer E30 for card E30 Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 11 12:23:16 hifi volumio[1045]: info: Updating Volume Controller Parameters: Device: 5 Name: E30 Mixer: E30 Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 11 12:23:16 hifi volumio[1045]: info: Disabling external Volume Control Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:16 hifi volumio[1045]: info: Preparing to generate the ALSA configuration file Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 11 12:23:16 hifi volumio[1045]: info: Asound.conf file unchanged, so no further update is needed Oct 11 12:23:16 hifi volumio[1045]: info: Output device has changed, restarting MPD Oct 11 12:23:16 hifi sudo[2097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 11 12:23:16 hifi sudo[2097]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:16 hifi volumio[1045]: info: Output device has changed, restarting Shairport Sync Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:23:16 hifi sudo[2097]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:16 hifi sudo[2099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 11 12:23:16 hifi sudo[2099]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:16 hifi systemd[1]: Stopping Music Player Daemon... Oct 11 12:23:16 hifi volumio[1045]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 11 12:23:16 hifi volumio[1045]: info: VolumeController:: Volume=0 Mute =false Oct 11 12:23:16 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:23:16 hifi systemd[1]: mpd.service: Succeeded. Oct 11 12:23:16 hifi systemd[1]: Stopped Music Player Daemon. Oct 11 12:23:16 hifi volumio[1045]: info: MPD Permissions set Oct 11 12:23:16 hifi systemd[1]: Starting Music Player Daemon... Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 11 12:23:16 hifi volumio[1045]: info: Starting Shairport Sync Oct 11 12:23:16 hifi sudo[2114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 11 12:23:16 hifi sudo[2114]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:16 hifi sudo[2106]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 11 12:23:16 hifi sudo[2106]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:16 hifi systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 11 12:23:16 hifi systemd[1]: shairport-sync.service: Succeeded. Oct 11 12:23:16 hifi sudo[2106]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:16 hifi systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 11 12:23:16 hifi sudo[2114]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:16 hifi systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 11 12:23:16 hifi volumio[1045]: info: Shairport-Sync Started Oct 11 12:23:16 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Oct 11 12:23:17 hifi mpd[2117]: Oct 11 11:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 11 12:23:17 hifi systemd[1]: Started Music Player Daemon. Oct 11 12:23:17 hifi sudo[2099]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:17 hifi volumio[1045]: error: updateQueue error: null Oct 11 12:23:18 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 11 12:23:20 hifi volumio[1045]: info: CoreStateMachine::getcurrentVolume Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrievevolume Oct 11 12:23:20 hifi volumio[1045]: info: VolumeController:: Volume=0 Mute =false Oct 11 12:23:20 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:23:20 hifi volumio[1045]: info: CoreStateMachine::updateTrackBlock Oct 11 12:23:20 hifi volumio[1045]: info: CorePlayQueue::getTrackBlock Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::volumioRetrievevolume Oct 11 12:23:20 hifi volumio[1045]: info: VolumeController:: Volume=0 Mute =false Oct 11 12:23:20 hifi volumio[1045]: info: CoreStateMachine::pushState Oct 11 12:23:20 hifi volumio[1045]: info: CoreCommandRouter::volumioPushState Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 11 12:23:24 hifi volumio[1045]: info: Received Get System Version Oct 11 12:23:24 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 11 12:23:29 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: wizard , openWizard Oct 11 12:23:29 hifi volumio[1045]: info: CoreCommandRouter::Reload Ui Oct 11 12:23:30 hifi sudo[2137]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 11 12:23:30 hifi sudo[2137]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:30 hifi sudo[2137]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:30 hifi sudo[2140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 11 12:23:30 hifi sudo[2140]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:30 hifi sudo[2140]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:30 hifi volumio[1045]: verbose: New Socket.io Connection to 192.168.86.203 from 192.168.86.163 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5 Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::volumioGetVisibleSources Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Oct 11 12:23:30 hifi volumio[1045]: info: Received Get System Info Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 12:23:30 hifi volumio[1045]: info: Discovery: Getting this device information Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 12:23:30 hifi volumio-remote-updater[680]: No test mode Oct 11 12:23:30 hifi volumio-remote-updater[680]: No alpha test mode Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Retrieving Cloud Streaming UI Oct 11 12:23:30 hifi volumio[1045]: info: Getting Tidal Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Getting Qobuz Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Asking plugin for UI Config Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Getting Spotify Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Asking plugin for UI Config Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Saving Spotify Acccount Oct 11 12:23:30 hifi volumio[1045]: info: Got Tidal Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Got it Oct 11 12:23:30 hifi volumio[1045]: info: Got it Oct 11 12:23:30 hifi volumio[1045]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Oct 11 12:23:30 hifi volumio[1045]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 11 12:23:30 hifi volumio[1045]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/90.0.4430.212 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::volumioGetVisibleSources Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: wizard , getWizardSteps Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , showActivationCode Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getAvailableTimezones Oct 11 12:23:30 hifi volumio[1045]: info: Received Get System Info Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 11 12:23:30 hifi volumio[1045]: info: Discovery: Getting this device information Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::volumioGetState Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 11 12:23:30 hifi volumio-remote-updater[680]: No test mode Oct 11 12:23:30 hifi volumio-remote-updater[680]: No alpha test mode Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 11 12:23:30 hifi volumio[1045]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Retrieving Cloud Streaming UI Oct 11 12:23:30 hifi volumio[1045]: info: Getting Tidal Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Getting Qobuz Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Asking plugin for UI Config Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Getting Spotify Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Asking plugin for UI Config Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: info: Saving Spotify Acccount Oct 11 12:23:30 hifi volumio[1045]: info: Got Tidal Cloud Configuration Oct 11 12:23:30 hifi volumio[1045]: info: Got it Oct 11 12:23:30 hifi volumio[1045]: info: Got it Oct 11 12:23:30 hifi volumio[1045]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 11 12:23:30 hifi volumio[1045]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 11 12:23:30 hifi volumio[1045]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Oct 11 12:23:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Oct 11 12:23:31 hifi volumio[1045]: info: Loading i18n strings for locale en Oct 11 12:23:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Oct 11 12:23:31 hifi volumio[1045]: info: Setting timezone to Europe/London Oct 11 12:23:31 hifi sudo[2152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Oct 11 12:23:31 hifi sudo[2152]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi sudo[2152]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:31 hifi sudo[2155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/London /etc/localtime Oct 11 12:23:31 hifi sudo[2155]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi sudo[2155]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:31 hifi sudo[2158]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Oct 11 12:23:31 hifi sudo[2158]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi sudo[2158]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:31 hifi sudo[2161]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/London Oct 11 12:23:31 hifi sudo[2161]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi dbus-daemon[684]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.20' (uid=0 pid=2162 comm="/usr/bin/timedatectl set-timezone Europe/London ") Oct 11 12:23:31 hifi systemd[1]: Starting Time & Date Service... Oct 11 12:23:31 hifi dbus-daemon[684]: [system] Successfully activated service 'org.freedesktop.timedate1' Oct 11 12:23:31 hifi systemd[1]: Started Time & Date Service. Oct 11 12:23:31 hifi sudo[2161]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:31 hifi volumio[1045]: Updating browse sources language Oct 11 12:23:31 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 12:23:31 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:31 hifi volumio[1045]: info: Fetching Streaming Services browse cache Oct 11 12:23:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Oct 11 12:23:31 hifi volumio[1045]: info: Loading i18n strings for locale en Oct 11 12:23:31 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Oct 11 12:23:31 hifi volumio[1045]: info: Setting timezone to UTC Oct 11 12:23:31 hifi sudo[2165]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Oct 11 12:23:31 hifi sudo[2165]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi sudo[2165]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:31 hifi sudo[2168]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/UTC /etc/localtime Oct 11 12:23:31 hifi sudo[2168]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:31 hifi sudo[2168]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi sudo[2171]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Oct 11 12:23:32 hifi sudo[2171]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi sudo[2171]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi sudo[2174]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Oct 11 12:23:32 hifi sudo[2174]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi systemd-timedated[2163]: Failed to set time zone: Permission denied Oct 11 12:23:32 hifi sudo[2174]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi volumio[1045]: Failed to set time zone: Access denied Oct 11 12:23:32 hifi volumio[1045]: info: Could not set timezone, retrying Oct 11 12:23:32 hifi volumio[1045]: Updating browse sources language Oct 11 12:23:32 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 12:23:32 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: appearance , setLanguage Oct 11 12:23:32 hifi volumio[1045]: info: Loading i18n strings for locale en Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: system , setTimezone Oct 11 12:23:32 hifi volumio[1045]: info: Setting timezone to Europe/London Oct 11 12:23:32 hifi sudo[2177]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/unlink /etc/localtime Oct 11 12:23:32 hifi sudo[2177]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi sudo[2177]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi sudo[2180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/ln -s /usr/share/zoneinfo/Europe/London /etc/localtime Oct 11 12:23:32 hifi sudo[2180]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi sudo[2180]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi sudo[2183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/localtime Oct 11 12:23:32 hifi sudo[2183]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi sudo[2183]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi sudo[2186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone Europe/London Oct 11 12:23:32 hifi sudo[2186]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi systemd-timedated[2163]: Failed to set time zone: Permission denied Oct 11 12:23:32 hifi sudo[2186]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:32 hifi volumio[1045]: Failed to set time zone: Access denied Oct 11 12:23:32 hifi volumio[1045]: info: Could not set timezone, retrying Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworksScanCache Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: network , getWirelessNetworks Oct 11 12:23:32 hifi sudo[2189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 11 12:23:32 hifi sudo[2189]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:32 hifi volumio[1045]: Updating browse sources language Oct 11 12:23:32 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 11 12:23:32 hifi volumio[1045]: Cannot find translation for source Spotify Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 12:23:32 hifi volumio[1045]: info: Fetching Streaming Services browse cache Oct 11 12:23:32 hifi volumio[1045]: info: Fetching Streaming Services browse cache Oct 11 12:23:32 hifi volumio[1045]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 11 12:23:33 hifi sudo[2192]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/timedatectl set-timezone UTC Oct 11 12:23:33 hifi sudo[2192]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 11 12:23:33 hifi systemd-timedated[2163]: Failed to set time zone: Permission denied Oct 11 12:23:33 hifi sudo[2192]: pam_unix(sudo:session): session closed for user root Oct 11 12:23:33 hifi volumio[1045]: Failed to set time zone: Access denied Oct 11 12:23:33 hifi volumio[1045]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 12:23:33 hifi volumio[1045]: Error: Command failed: /usr/bin/sudo /usr/bin/timedatectl set-timezone 'UTC' Oct 11 12:23:33 hifi volumio[1045]: Failed to set time zone: Access denied Oct 11 12:23:33 hifi volumio[1045]: at checkExecSyncError (child_process.js:790:11) Oct 11 12:23:33 hifi volumio[1045]: at execSync (child_process.js:863:15) Oct 11 12:23:33 hifi volumio[1045]: at Timeout._onTimeout (/volumio/app/plugins/system_controller/system/index.js:1575:9) Oct 11 12:23:33 hifi volumio[1045]: at listOnTimeout (internal/timers.js:557:17) Oct 11 12:23:33 hifi volumio[1045]: at processTimers (internal/timers.js:500:7) { Oct 11 12:23:33 hifi volumio[1045]: status: 1, Oct 11 12:23:33 hifi volumio[1045]: signal: null, Oct 11 12:23:33 hifi volumio[1045]: output: [ null, '', 'Failed to set time zone: Access denied\n' ], Oct 11 12:23:33 hifi volumio[1045]: pid: 2191, Oct 11 12:23:33 hifi volumio[1045]: stdout: '', Oct 11 12:23:33 hifi volumio[1045]: stderr: 'Failed to set time zone: Access denied\n' Oct 11 12:23:33 hifi volumio[1045]: } Oct 11 12:23:33 hifi volumio[1045]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 11 12:23:33 hifi sudo[2203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-11 12:22 Oct 11 12:23:33 hifi sudo[2203]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:33:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="ee834e1c2a28de3c5d8c48611ecf1167"