May 28 09:54:11 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 28 09:54:23 volumio kernel: usb 1-1.4: new high-speed USB device number 4 using dwc_otg May 28 09:54:23 volumio kernel: usb 1-1.4: New USB device found, idVendor=0781, idProduct=5595, bcdDevice= 1.00 May 28 09:54:23 volumio kernel: usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 28 09:54:23 volumio kernel: usb 1-1.4: Product: Ultra USB 3.0 May 28 09:54:23 volumio kernel: usb 1-1.4: Manufacturer: SanDisk May 28 09:54:23 volumio kernel: usb 1-1.4: SerialNumber: 4C531000370924103441 May 28 09:54:23 volumio kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected May 28 09:54:23 volumio kernel: scsi host0: usb-storage 1-1.4:1.0 May 28 09:54:24 volumio kernel: scsi 0:0:0:0: Direct-Access SanDisk Ultra USB 3.0 1.00 PQ: 0 ANSI: 6 May 28 09:54:24 volumio kernel: sd 0:0:0:0: [sda] 242614272 512-byte logical blocks: (124 GB/116 GiB) May 28 09:54:24 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off May 28 09:54:24 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 May 28 09:54:24 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA May 28 09:54:24 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 May 28 09:54:24 volumio kernel: sda: sda1 May 28 09:54:24 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk May 28 09:54:25 volumio volumio[1240]: info: Mounting Device 9095-4E24 May 28 09:54:25 volumio sudo[3701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/9095-4E24 -o noatime May 28 09:54:25 volumio sudo[3701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:54:25 volumio sudo[3701]: pam_unix(sudo:session): session closed for user root May 28 09:54:41 volumio systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories... May 28 09:54:41 volumio systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully. May 28 09:54:41 volumio systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories. May 28 09:54:41 volumio systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully. May 28 09:54:41 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... May 28 09:54:41 volumio dbus-daemon[594]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.51' (uid=0 pid=3738 comm="timedatectl show --property=NTPSynchronized --valu") May 28 09:54:41 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service... May 28 09:54:41 volumio dbus-daemon[594]: [system] Successfully activated service 'org.freedesktop.timedate1' May 28 09:54:41 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service. May 28 09:54:41 volumio setdatetime-helper.sh[3737]: Time is already synchronized. May 28 09:54:41 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. May 28 09:54:41 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. May 28 09:54:54 volumio kernel: usb 1-1.4: USB disconnect, device number 4 May 28 09:54:54 volumio kernel: hwmon hwmon1: Undervoltage detected! May 28 09:54:54 volumio volumio[1240]: info: Partition removed: {"syspath":"/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-path/platform-3f980000.usb-usb-0:1.4:1.0-scsi-0:0:0:0-part1 /dev/disk/by-id/usb-SanDisk_Ultra_USB_3.0_4C531000370924103441-0:0-part1 /dev/disk/by-uuid/9095-4E24 /dev/disk/by-partuuid/448ad351-01","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"27","ID_BUS":"usb","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"9095-4E24","ID_FS_UUID_ENC":"9095-4E24","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"Ultra_USB_3.0","ID_MODEL_ENC":"Ultra\\x20USB\\x203.0\\x20\\x20\\x20","ID_MODEL_ID":"5595","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"32768","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"242581504","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"448ad351-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"448ad351","ID_PATH":"platform-3f980000.usb-usb-0:1.4:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-3f980000_usb-usb-0_1_4_1_0-scsi-0_0_0_0","ID_REVISION":"1.00","ID_SERIAL":"SanDisk_Ultra_USB_3.0_4C531000370924103441-0:0","ID_SERIAL_SHORT":"4C531000370924103441","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"Ultra_USB_3.0","ID_USB_MODEL_ENC":"Ultra\\x20USB\\x203.0\\x20\\x20\\x20","ID_USB_MODEL_ID":"5595","ID_USB_REVISION":"1.00","ID_USB_SERIAL":"SanDisk_Ultra_USB_3.0_4C531000370924103441-0:0","ID_USB_SERIAL_SHORT":"4C531000370924103441","ID_USB_TYPE":"disk","ID_USB_VENDOR":"SanDisk","ID_USB_VENDOR_ENC":"SanDisk\\x20","ID_USB_VENDOR_ID":"0781","ID_VENDOR":"SanDisk","ID_VENDOR_ENC":"SanDisk\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"2018","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"887951270"} May 28 09:54:54 volumio sudo[3764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1 May 28 09:54:54 volumio sudo[3764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:54:54 volumio systemd[1]: media-9095\x2d4E24.mount: Deactivated successfully. May 28 09:54:54 volumio sudo[3764]: pam_unix(sudo:session): session closed for user root May 28 09:54:54 volumio kernel: usb 1-1.5: new full-speed USB device number 5 using dwc_otg May 28 09:54:54 volumio kernel: usb 1-1.5: New USB device found, idVendor=0d8c, idProduct=000c, bcdDevice= 1.00 May 28 09:54:54 volumio kernel: usb 1-1.5: New USB device strings: Mfr=0, Product=1, SerialNumber=0 May 28 09:54:54 volumio kernel: usb 1-1.5: Product: C-Media USB Headphone Set May 28 09:54:54 volumio kernel: input: C-Media USB Headphone Set as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.5/1-1.5:1.2/0003:0D8C:000C.0001/input/input0 May 28 09:54:54 volumio kernel: hid-generic 0003:0D8C:000C.0001: input,hidraw0: USB HID v1.00 Device [C-Media USB Headphone Set ] on usb-3f980000.usb-1.5/input2 May 28 09:54:55 volumio kernel: usbcore: registered new interface driver snd-usb-audio May 28 09:54:55 volumio (udev-worker)[3756]: event0: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. May 28 09:54:55 volumio kernel: usb 1-1.4: new high-speed USB device number 6 using dwc_otg May 28 09:54:55 volumio volumio[1240]: info: May 28 09:54:55 volumio volumio[1240]: ---------------------------- USB Audio Device Attached May 28 09:54:55 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach May 28 09:54:55 volumio kernel: usb 1-1.4: New USB device found, idVendor=0781, idProduct=5595, bcdDevice= 1.00 May 28 09:54:55 volumio kernel: usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 28 09:54:55 volumio kernel: usb 1-1.4: Product: Ultra USB 3.0 May 28 09:54:55 volumio kernel: usb 1-1.4: Manufacturer: SanDisk May 28 09:54:55 volumio kernel: usb 1-1.4: SerialNumber: 4C531000370924103441 May 28 09:54:55 volumio kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected May 28 09:54:55 volumio kernel: scsi host0: usb-storage 1-1.4:1.0 May 28 09:54:56 volumio kernel: scsi 0:0:0:0: Direct-Access SanDisk Ultra USB 3.0 1.00 PQ: 0 ANSI: 6 May 28 09:54:56 volumio kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 May 28 09:54:56 volumio kernel: sd 0:0:0:0: [sda] 242614272 512-byte logical blocks: (124 GB/116 GiB) May 28 09:54:56 volumio kernel: sd 0:0:0:0: [sda] Write Protect is off May 28 09:54:56 volumio kernel: sd 0:0:0:0: [sda] Mode Sense: 43 00 00 00 May 28 09:54:56 volumio kernel: sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA May 28 09:54:56 volumio kernel: sda: sda1 May 28 09:54:56 volumio kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk May 28 09:54:56 volumio volumio[1240]: info: Mounting Device 9095-4E24 May 28 09:54:57 volumio sudo[3788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/9095-4E24 -o noatime May 28 09:54:57 volumio sudo[3788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:54:57 volumio sudo[3788]: pam_unix(sudo:session): session closed for user root May 28 09:54:58 volumio volumio[1240]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/9095-4E24 May 28 09:54:59 volumio volumio[1240]: info: Scanning removed location : "USB/9095-4E24" May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: info: May 28 09:54:59 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: info: May 28 09:54:59 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: info: May 28 09:54:59 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 11 milliseconds May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 8 milliseconds May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 8 milliseconds May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 7 milliseconds May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: info: Command Router : Notfying DB Updatetrue May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: info: Command Router : Notfying DB Updatetrue May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::Close All Modals sent May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:54:59 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: No code May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:54:59 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: No code May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: ------------------------------ 243ms May 28 09:54:59 volumio volumio[1240]: info: ------------------------------ 239ms May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 239 milliseconds May 28 09:54:59 volumio volumio[1240]: info: sendMpdCommand status took 238 milliseconds May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: info: Command Router : Notfying DB Updatetrue May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::Close All Modals sent May 28 09:54:59 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:54:59 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:54:59 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: No code May 28 09:54:59 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:54:59 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:54:59 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:54:59 volumio volumio[1240]: info: ------------------------------ 311ms May 28 09:55:00 volumio kernel: hwmon hwmon1: Voltage normalised May 28 09:55:00 volumio volumio[1240]: info: MPD Database updated - AlbumList cache refreshed May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: database May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: MPD Database updated - AlbumList cache refreshed May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: database May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: MPD Database updated - AlbumList cache refreshed May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: database May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: May 28 09:55:00 volumio volumio[1240]: ---------------------------- MPD announces state update: update May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:00 volumio volumio[1240]: info: ControllerMpd::getState May 28 09:55:00 volumio volumio[1240]: verbose: ControllerMpd::sendMpdCommand status May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 171 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 170 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 171 milliseconds May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: Command Router : Notfying DB Updatefalse May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::Close All Modals sent May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 302ms May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 302ms May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 616 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 627 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 628 milliseconds May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: Command Router : Notfying DB Updatefalse May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::Close All Modals sent May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 710ms May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 710ms May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 785 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 783 milliseconds May 28 09:55:01 volumio volumio[1240]: info: sendMpdCommand status took 783 milliseconds May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: Command Router : Notfying DB Updatefalse May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::Close All Modals sent May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: verbose: ControllerMpd::parseState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ControllerMpd::pushState May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::servicePushState May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 28 09:55:01 volumio volumio[1240]: verbose: CURRENT POSITION 0 May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState stateService stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::syncState currentStatus stop May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: No code May 28 09:55:01 volumio volumio[1240]: info: CoreStateMachine::pushState May 28 09:55:01 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:01 volumio volumio[1240]: info: CoreCommandRouter::volumioPushState May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 872ms May 28 09:55:01 volumio volumio[1240]: info: ------------------------------ 872ms May 28 09:55:11 volumio systemd[1]: systemd-timedated.service: Deactivated successfully. May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:12 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:12 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:12 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:12 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:12 volumio volumio[1240]: verbose: New Socket.io Connection to 192.168.1.9:3000 from 192.168.1.4 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:12 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard May 28 09:55:12 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard May 28 09:55:13 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:13 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:13 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:13 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:13 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:13 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:14 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:14 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:16 volumio sudo[3850]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 28 09:55:16 volumio sudo[3850]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:16 volumio sudo[3850]: pam_unix(sudo:session): session closed for user root May 28 09:55:16 volumio sudo[3852]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 28 09:55:16 volumio sudo[3852]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:16 volumio sudo[3852]: pam_unix(sudo:session): session closed for user root May 28 09:55:16 volumio volumio[1240]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.4 UA: Mozilla/5.0 (Linux; Android 15; 23106RN0DA Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:17 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:17 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:17 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:17 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:17 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:18 volumio sudo[3870]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 28 09:55:18 volumio sudo[3870]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:18 volumio sudo[3870]: pam_unix(sudo:session): session closed for user root May 28 09:55:18 volumio sudo[3872]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 28 09:55:18 volumio sudo[3872]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:18 volumio sudo[3872]: pam_unix(sudo:session): session closed for user root May 28 09:55:18 volumio volumio[1240]: verbose: New Socket.io Connection to 192.168.1.9 from 192.168.1.4 UA: Mozilla/5.0 (Linux; Android 15; 23106RN0DA Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/136.0.7103.61 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::volumioGetVisibleSources May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:18 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 28 09:55:18 volumio volumio[1240]: info: Received Get System Info May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:18 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:18 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:18 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:18 volumio volumio[1240]: info: Listing playlists May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 28 09:55:18 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 28 09:55:19 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 09:55:19 volumio volumio[1240]: info: Received Get System Info May 28 09:55:19 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:19 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:19 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:19 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:19 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:19 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:20 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 28 09:55:21 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 09:55:21 volumio volumio[1240]: info: Received Get System Info May 28 09:55:21 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:21 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:21 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:21 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:21 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:21 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:24 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 28 09:55:24 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 28 09:55:28 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 28 09:55:35 volumio volumio[1240]: info: Enabling plugin peppymeterbasic May 28 09:55:35 volumio volumio[1240]: info: Loading plugin "peppymeterbasic"... May 28 09:55:35 volumio volumio[1240]: info: Preparing to generate the ALSA configuration file May 28 09:55:35 volumio volumio[1240]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 28 09:55:35 volumio volumio[1240]: info: Reading ALSA contributions from plugins. May 28 09:55:35 volumio volumio[1240]: info: Asound.conf file written May 28 09:55:35 volumio sudo[3896]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf May 28 09:55:35 volumio sudo[3896]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:35 volumio sudo[3896]: pam_unix(sudo:session): session closed for user root May 28 09:55:35 volumio volumio[1240]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 May 28 09:55:35 volumio volumio[1240]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 May 28 09:55:35 volumio volumio[1240]: info: Output device has changed, restarting MPD May 28 09:55:35 volumio volumio[1240]: info: Output device has changed, restarting Shairport Sync May 28 09:55:35 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:35 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 09:55:35 volumio sudo[3902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 28 09:55:35 volumio sudo[3902]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:35 volumio sudo[3902]: pam_unix(sudo:session): session closed for user root May 28 09:55:35 volumio sudo[3904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 28 09:55:35 volumio sudo[3904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:36 volumio volumio[1240]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 28 09:55:36 volumio volumio[1240]: info: PLUGIN START: peppymeterbasic May 28 09:55:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile May 28 09:55:36 volumio volumio[1240]: info: Preparing to generate the ALSA configuration file May 28 09:55:36 volumio volumio[1240]: info: Done. May 28 09:55:36 volumio volumio[1240]: info: The plugin peppymeterbasic has an ALSA contribution file peppy_in.peppy_out.6.conf May 28 09:55:36 volumio volumio[1240]: info: Reading ALSA contributions from plugins. May 28 09:55:36 volumio volumio[1240]: info: MPD Permissions set May 28 09:55:36 volumio volumio[1240]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: Starting Shairport Sync May 28 09:55:36 volumio volumio[1240]: info: Asound.conf file unchanged, so no further update is needed May 28 09:55:36 volumio volumio[1240]: info: Output device has changed, restarting MPD May 28 09:55:36 volumio sudo[3919]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 28 09:55:36 volumio sudo[3919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:36 volumio volumio[1240]: info: Output device has changed, restarting Shairport Sync May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 09:55:36 volumio sudo[3921]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 28 09:55:36 volumio sudo[3921]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:36 volumio sudo[3921]: pam_unix(sudo:session): session closed for user root May 28 09:55:36 volumio sudo[3924]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 28 09:55:36 volumio sudo[3924]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 28 09:55:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 28 09:55:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 09:55:36 volumio systemd[1]: shairport-sync.service: Consumed 5.447s CPU time. May 28 09:55:36 volumio volumio[1240]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 28 09:55:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 09:55:36 volumio volumio[1240]: info: MPD Permissions set May 28 09:55:36 volumio sudo[3919]: pam_unix(sudo:session): session closed for user root May 28 09:55:36 volumio volumio[1240]: info: Shairport-Sync Started May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 28 09:55:36 volumio volumio[1240]: info: Starting Shairport Sync May 28 09:55:36 volumio sudo[3941]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 28 09:55:36 volumio sudo[3941]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) May 28 09:55:36 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... May 28 09:55:36 volumio systemd[1]: shairport-sync.service: Deactivated successfully. May 28 09:55:36 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 09:55:36 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. May 28 09:55:36 volumio sudo[3941]: pam_unix(sudo:session): session closed for user root May 28 09:55:36 volumio volumio[1240]: info: Shairport-Sync Started May 28 09:55:36 volumio systemd[1]: mpd.service: Deactivated successfully. May 28 09:55:36 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. May 28 09:55:36 volumio systemd[1]: mpd.service: Consumed 6.682s CPU time. May 28 09:55:36 volumio systemd[1]: mpd.socket: Deactivated successfully. May 28 09:55:36 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. May 28 09:55:36 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... May 28 09:55:36 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. May 28 09:55:36 volumio systemd[1]: Starting mpd.service - Music Player Daemon... May 28 09:55:36 volumio sudo[3945]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 28 09:55:36 volumio sudo[3945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) May 28 09:55:36 volumio sudo[3945]: pam_unix(sudo:session): session closed for user root May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 28 09:55:37 volumio volumio[1240]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 28 09:55:37 volumio volumio[1240]: info: Received Get System Version May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 28 09:55:37 volumio volumio[1240]: info: Received Get System Info May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:37 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:37 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:37 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:40 volumio mpd[3961]: 2025-05-28T09:55:40 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 28 09:55:40 volumio systemd[1]: Started mpd.service - Music Player Daemon. May 28 09:55:40 volumio sudo[3904]: pam_unix(sudo:session): session closed for user root May 28 09:55:40 volumio sudo[3924]: pam_unix(sudo:session): session closed for user root May 28 09:55:40 volumio volumio[1240]: error: MPD error: The expression evaluated to a falsy value: May 28 09:55:40 volumio volumio[1240]: assert.ok(self.idling) May 28 09:55:40 volumio volumio[1240]: error: The expression evaluated to a falsy value: May 28 09:55:40 volumio volumio[1240]: assert.ok(self.idling) May 28 09:55:40 volumio volumio[1240]: error: updateQueue error: null May 28 09:55:41 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 28 09:55:41 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 28 09:55:41 volumio volumio[1240]: info: Discovery: Getting this device information May 28 09:55:41 volumio volumio[1240]: info: CoreCommandRouter::volumioGetState May 28 09:55:41 volumio volumio[1240]: info: CorePlayQueue::getTrack 0 May 28 09:55:41 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 28 09:55:42 volumio volumio[1240]: info: CoreCommandRouter::getUIConfigOnPlugin May 28 09:55:42 volumio volumio[1240]: info: PeppyMeterBasic ---list is random,bar,blue,vintage,dash,gas,rainbow,grunge,royal,compass,gold,black-white,white-red,orange,blue-2,emerald,red,tube,vertical-linear,vertical-circular,big-bang,ring,relax,steam-punk,fantasy,chillout May 28 09:55:42 volumio volumio[1240]: info: PeppyMeterBasic ---800x480-test May 28 09:55:56 volumio volumio[1240]: info: CALLMETHOD: user_interface peppymeterbasic dlmeter [object Object] May 28 09:55:56 volumio volumio[1240]: info: CoreCommandRouter::executeOnPlugin: peppymeterbasic , dlmeter May 28 09:55:59 volumio volumio[1240]: --2025-05-28 09:55:56-- https://github.com/balbuze/Meter-peppymeter/raw/main/Zipped-folders/Choose May 28 09:55:59 volumio volumio[1240]: Resolving github.com (github.com)... 20.205.243.166 May 28 09:55:59 volumio volumio[1240]: Connecting to github.com (github.com)|20.205.243.166|:443... connected. May 28 09:55:59 volumio volumio[1240]: HTTP request sent, awaiting response... 404 Not Found May 28 09:55:59 volumio volumio[1240]: 2025-05-28 09:55:57 ERROR 404: Not Found. May 28 09:55:59 volumio volumio[1240]: --2025-05-28 09:55:57-- http://a/ May 28 09:55:59 volumio volumio[1240]: Resolving a (a)... failed: Device or resource busy. May 28 09:55:59 volumio volumio[1240]: wget: unable to resolve host address ‘a’ May 28 09:55:59 volumio volumio[1240]: --2025-05-28 09:55:57-- http://packet.zip/ May 28 09:55:59 volumio volumio[1240]: Resolving packet.zip (packet.zip)... 162.255.119.167 May 28 09:55:59 volumio volumio[1240]: Connecting to packet.zip (packet.zip)|162.255.119.167|:80... connected. May 28 09:55:59 volumio volumio[1240]: HTTP request sent, awaiting response... 302 Found May 28 09:55:59 volumio volumio[1240]: Location: http://www.packet.zip/ [following] May 28 09:55:59 volumio volumio[1240]: --2025-05-28 09:55:58-- http://www.packet.zip/ May 28 09:55:59 volumio volumio[1240]: Resolving www.packet.zip (www.packet.zip)... 91.195.240.19 May 28 09:55:59 volumio volumio[1240]: Connecting to www.packet.zip (www.packet.zip)|91.195.240.19|:80... connected. May 28 09:55:59 volumio volumio[1240]: HTTP request sent, awaiting response... 403 Forbidden May 28 09:55:59 volumio volumio[1240]: 2025-05-28 09:55:59 ERROR 403: Forbidden. May 28 09:55:59 volumio volumio[1240]: error: PeppyMeterBasic --- An error occurs while downloading or installing Meters May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove 'a': No such file or directory May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove 'packet.zip*': No such file or directory May 28 09:55:59 volumio volumio[1240]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 09:55:59 volumio volumio[1240]: Error: Command failed: /bin/rm /tmp/Choose a packet.zip* May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove '/tmp/Choose': No such file or directory May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove 'a': No such file or directory May 28 09:55:59 volumio volumio[1240]: /bin/rm: cannot remove 'packet.zip*': No such file or directory May 28 09:55:59 volumio volumio[1240]: at checkExecSyncError (node:child_process:887:11) May 28 09:55:59 volumio volumio[1240]: at execSync (node:child_process:959:15) May 28 09:55:59 volumio volumio[1240]: at /data/plugins/user_interface/peppymeterbasic/index.js:700:17 May 28 09:55:59 volumio volumio[1240]: at new Promise () May 28 09:55:59 volumio volumio[1240]: at peppymeterbasic.dlmeter (/data/plugins/user_interface/peppymeterbasic/index.js:675:12) May 28 09:55:59 volumio volumio[1240]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) May 28 09:55:59 volumio volumio[1240]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:337:42) May 28 09:55:59 volumio volumio[1240]: at Socket.emit (node:events:514:28) May 28 09:55:59 volumio volumio[1240]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 May 28 09:55:59 volumio volumio[1240]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) { May 28 09:55:59 volumio volumio[1240]: status: 1, May 28 09:55:59 volumio volumio[1240]: signal: null, May 28 09:55:59 volumio volumio[1240]: output: [ May 28 09:55:59 volumio volumio[1240]: null, May 28 09:55:59 volumio volumio[1240]: , May 28 09:55:59 volumio volumio[1240]: May 28 09:55:59 volumio volumio[1240]: ], May 28 09:55:59 volumio volumio[1240]: pid: 4012, May 28 09:55:59 volumio volumio[1240]: stdout: , May 28 09:55:59 volumio volumio[1240]: stderr: May 28 09:55:59 volumio volumio[1240]: } May 28 09:55:59 volumio volumio[1240]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 28 09:55:59 volumio sudo[4028]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-05-28 09:54' May 28 09:55:59 volumio sudo[4028]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="fd567ba9bc0dc34c0403e2d5b72a0f46467d1983" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri May 23 08:02:06 UTC 2025" VOLUMIO_VERSION="0.069" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="76fa67e30b28261e1dc7c3a89e610b9e"