-- Logs begin at Wed 2025-07-02 10:21:19 UTC, end at Wed 2025-07-02 15:43:24 UTC. -- Jul 02 15:42:41 volacer kernel: usb 3-3: USB disconnect, device number 2 Jul 02 15:42:41 volacer kernel: sd 1:0:0:0: [sda] tag#10 uas_zap_pending 0 uas-tag 1 inflight: CMD Jul 02 15:42:41 volacer kernel: sd 1:0:0:0: [sda] tag#10 CDB: Read(10) 28 00 11 19 8d ff 00 00 08 00 Jul 02 15:42:41 volacer kernel: sd 1:0:0:0: [sda] tag#10 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK cmd_age=0s Jul 02 15:42:41 volacer kernel: sd 1:0:0:0: [sda] tag#10 CDB: Read(10) 28 00 11 19 8d ff 00 00 08 00 Jul 02 15:42:41 volacer kernel: I/O error, dev sda, sector 286887423 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286887423 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286879423 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859920, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859921, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859922, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859923, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859924, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859925, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859926, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859927, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859928, lost async page write Jul 02 15:42:41 volacer kernel: Buffer I/O error on dev sda1, logical block 35859929, lost async page write Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 10863 op 0x1:(WRITE) flags 0x0 phys_seg 1 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286880447 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286881471 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286887423 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286882495 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286883519 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer kernel: device offline error, dev sda, sector 286884543 op 0x1:(WRITE) flags 0x4000 phys_seg 128 prio class 2 Jul 02 15:42:41 volacer mount.exfat[1176]: failed to write cluster 0x11190f Jul 02 15:42:41 volacer volumio[903]: info: Executing endpoint cdPostRip Jul 02 15:42:41 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , notifyPostRip Jul 02 15:42:41 volacer volumio[903]: info: CD RIP Terminated Jul 02 15:42:42 volacer volumio[903]: info: Set CD Speed to 4X Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:42 volacer volumio[903]: info: Jul 02 15:42:42 volacer volumio[903]: ---------------------------- MPD announces state update: update Jul 02 15:42:42 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:42 volacer volumio[903]: info: Updating MPD DB after CD rip Jul 02 15:42:42 volacer volumio[903]: info: Syncing changes to disk Jul 02 15:42:42 volacer volumio[903]: info: Cleaning abcde folders after CD rip Jul 02 15:42:42 volacer volumio[903]: info: sendMpdCommand status took 9 milliseconds Jul 02 15:42:42 volacer volumio[903]: info: sendMpdCommand status took 2 milliseconds Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:42 volacer volumio[903]: info: Command Router : Notfying DB Updatetrue Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:42 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:42 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:42 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:42 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:42 volacer volumio[903]: 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} Jul 02 15:42:42 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:42 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:42 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:42 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:42 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:42 volacer volumio[903]: info: No code Jul 02 15:42:42 volacer kernel: sr 2:0:0:0: ioctl_internal_command: ILLEGAL REQUEST asc=0x53 ascq=0x2 Jul 02 15:42:42 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:42 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:42 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:42 volacer volumio[903]: info: ------------------------------ 73ms Jul 02 15:42:42 volacer volumio[903]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.7/usb3/3-3/3-3:1.0/host1/target1:0:0/1:0:0:0/block/sda/sda1","ACTION":"remove","DEVLINKS":"/dev/disk/by-id/ata-SSD_512GB_YS202010443858HP-part1 /dev/disk/by-label/VOLUMIO /dev/disk/by-path/pci-0000:00:1d.7-usb-0:3:1.0-scsi-0:0:0:0-part1 /dev/disk/by-partuuid/bd27ec4c-01 /dev/disk/by-uuid/E0CB-D669","DEVNAME":"/dev/sda1","DEVPATH":"/devices/pci0000:00/0000:00:1d.7/usb3/3-3/3-3:1.0/host1/target1:0:0/1:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"1","ID_ATA":"1","ID_ATA_FEATURE_SET_PM":"1","ID_ATA_FEATURE_SET_PM_ENABLED":"1","ID_ATA_FEATURE_SET_SECURITY":"1","ID_ATA_FEATURE_SET_SECURITY_ENABLED":"0","ID_ATA_FEATURE_SET_SECURITY_ENHANCED_ERASE_UNIT_MIN":"2","ID_ATA_FEATURE_SET_SECURITY_ERASE_UNIT_MIN":"2","ID_ATA_FEATURE_SET_SMART":"1","ID_ATA_FEATURE_SET_SMART_ENABLED":"1","ID_ATA_ROTATION_RATE_RPM":"0","ID_ATA_SATA":"1","ID_ATA_SATA_SIGNAL_RATE_GEN1":"1","ID_ATA_SATA_SIGNAL_RATE_GEN2":"1","ID_ATA_WRITE_CACHE":"1","ID_ATA_WRITE_CACHE_ENABLED":"1","ID_BUS":"ata","ID_FS_LABEL":"VOLUMIO","ID_FS_LABEL_ENC":"VOLUMIO","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"E0CB-D669","ID_FS_UUID_ENC":"E0CB-D669","ID_FS_VERSION":"1.0","ID_MODEL":"SSD_512GB","ID_MODEL_ENC":"SSD\\x20512GB\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20\\x20","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"63","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"1000206837","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"bd27ec4c-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"bd27ec4c","ID_PATH":"pci-0000:00:1d.7-usb-0:3:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_7-usb-0_3_1_0-scsi-0_0_0_0","ID_REVISION":"HP3414B5","ID_SERIAL":"SSD_512GB_YS202010443858HP","ID_SERIAL_SHORT":"YS202010443858HP","ID_TYPE":"disk","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"3248","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"1840473"} Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer kernel: sd 1:0:0:0: [sda] Synchronizing SCSI cache Jul 02 15:42:42 volacer sudo[21628]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1 Jul 02 15:42:42 volacer sudo[21628]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer sudo[21628]: pam_unix(sudo:session): session closed for user root Jul 02 15:42:42 volacer volumio[903]: umount: /media/VOLUMIO: target is busy. Jul 02 15:42:42 volacer volumio[903]: error: Failed to umount VOLUMIO: Error: Command failed: /usr/bin/sudo /bin/umount -f "/dev/sda1" Jul 02 15:42:42 volacer volumio[903]: umount: /media/VOLUMIO: target is busy. Jul 02 15:42:42 volacer mount.exfat[1176]: failed to read cluster 0x111762 Jul 02 15:42:42 volacer mount.exfat[1176]: non-zero reference counter (1) for '03.Calling_You_(Bob_Telson)_Aus_OUT_OF_ROSENHEIMBAGDAD_CAFÉ.flac' Jul 02 15:42:42 volacer mount.exfat[1176]: failed to write super block Jul 02 15:42:42 volacer volumio[903]: info: MPD Database updated - AlbumList cache refreshed Jul 02 15:42:42 volacer volumio[903]: info: Jul 02 15:42:42 volacer volumio[903]: ---------------------------- MPD announces state update: database Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:42 volacer volumio[903]: info: Jul 02 15:42:42 volacer volumio[903]: ---------------------------- MPD announces state update: update Jul 02 15:42:42 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:42 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:42 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:43 volacer kernel: sd 1:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK Jul 02 15:42:43 volacer volumio[903]: info: sendMpdCommand status took 348 milliseconds Jul 02 15:42:43 volacer volumio[903]: info: sendMpdCommand status took 349 milliseconds Jul 02 15:42:43 volacer volumio[903]: info: sendMpdCommand status took 348 milliseconds Jul 02 15:42:43 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:43 volacer kernel: usb 3-3: new high-speed USB device number 4 using ehci-pci Jul 02 15:42:43 volacer volumio[903]: info: Command Router : Notfying DB Updatefalse Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent Jul 02 15:42:43 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:43 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:43 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: 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} Jul 02 15:42:43 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: No code Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: 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} Jul 02 15:42:43 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: No code Jul 02 15:42:43 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:43 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:43 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:43 volacer volumio[903]: info: ------------------------------ 396ms Jul 02 15:42:43 volacer volumio[903]: info: ------------------------------ 397ms Jul 02 15:42:43 volacer kernel: usb 3-3: New USB device found, idVendor=0dd8, idProduct=3908, bcdDevice= 2.06 Jul 02 15:42:43 volacer kernel: usb 3-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Jul 02 15:42:43 volacer kernel: usb 3-3: Product: DISK 3.2 Jul 02 15:42:43 volacer kernel: usb 3-3: Manufacturer: Netac Jul 02 15:42:43 volacer kernel: usb 3-3: SerialNumber: DD56419884345 Jul 02 15:42:43 volacer kernel: scsi host8: uas Jul 02 15:42:43 volacer kernel: scsi 8:0:0:0: Direct-Access Netac DISK 3.2 0206 PQ: 0 ANSI: 6 Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: Attached scsi generic sg0 type 0 Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] 1000215216 512-byte logical blocks: (512 GB/477 GiB) Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] 4096-byte physical blocks Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Write Protect is off Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Mode Sense: 5f 00 00 08 Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Preferred minimum I/O size 4096 bytes Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Optimal transfer size 33553920 bytes not a multiple of preferred minimum block size (4096 bytes) Jul 02 15:42:43 volacer kernel: sde: sde1 Jul 02 15:42:43 volacer kernel: sd 8:0:0:0: [sde] Attached SCSI disk Jul 02 15:42:44 volacer volumio[903]: info: Mounting Device VOLUMIO Jul 02 15:42:44 volacer volumio[903]: /bin/mkdir: cannot create directory ‘/mnt/USB/VOLUMIO’: File exists Jul 02 15:42:44 volacer volumio[903]: error: Failed to create folder Error: Command failed: /bin/mkdir -m 777 "/mnt/USB/VOLUMIO" Jul 02 15:42:44 volacer volumio[903]: /bin/mkdir: cannot create directory ‘/mnt/USB/VOLUMIO’: File exists Jul 02 15:42:44 volacer sudo[21644]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sde1 /mnt/USB/VOLUMIO -o noatime Jul 02 15:42:44 volacer sudo[21644]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 02 15:42:44 volacer mount.exfat[21646]: volume was not unmounted cleanly Jul 02 15:42:44 volacer sudo[21644]: pam_unix(sudo:session): session closed for user root Jul 02 15:42:44 volacer volumio[903]: WARN: volume was not unmounted cleanly. Jul 02 15:42:44 volacer volumio[903]: fuse: bad mount point `/mnt/USB/VOLUMIO': Transport endpoint is not connected Jul 02 15:42:44 volacer volumio[903]: error: Failed to mount VOLUMIO: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sde1" "/mnt/USB/VOLUMIO" -o noatime Jul 02 15:42:44 volacer volumio[903]: WARN: volume was not unmounted cleanly. Jul 02 15:42:44 volacer volumio[903]: fuse: bad mount point `/mnt/USB/VOLUMIO': Transport endpoint is not connected Jul 02 15:42:46 volacer volumio[903]: info: CoreCommandRouter::volumioGetState Jul 02 15:42:46 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:46 volacer volumio[903]: info: Clearing queue from CD entries Jul 02 15:42:46 volacer volumio[903]: info: CoreCommandRouter::volumioPushQueue Jul 02 15:42:46 volacer volumio[903]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesAudio CD Jul 02 15:42:46 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 02 15:42:47 volacer volumio[903]: info: Scanning removed location : "USB/VOLUMIO" Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:47 volacer volumio[903]: info: Jul 02 15:42:47 volacer volumio[903]: ---------------------------- MPD announces state update: update Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:47 volacer volumio[903]: info: MPD Database updated - AlbumList cache refreshed Jul 02 15:42:47 volacer volumio[903]: info: Jul 02 15:42:47 volacer volumio[903]: ---------------------------- MPD announces state update: database Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:47 volacer volumio[903]: info: Jul 02 15:42:47 volacer volumio[903]: ---------------------------- MPD announces state update: update Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::getState Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status Jul 02 15:42:47 volacer volumio[903]: info: sendMpdCommand status took 1 milliseconds Jul 02 15:42:47 volacer volumio[903]: info: sendMpdCommand status took 2 milliseconds Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:47 volacer volumio[903]: info: Command Router : Notfying DB Updatefalse Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: 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} Jul 02 15:42:47 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: No code Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: ------------------------------ 31ms Jul 02 15:42:47 volacer volumio[903]: info: sendMpdCommand status took 56 milliseconds Jul 02 15:42:47 volacer volumio[903]: info: sendMpdCommand status took 57 milliseconds Jul 02 15:42:47 volacer volumio[903]: info: sendMpdCommand status took 57 milliseconds Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:47 volacer volumio[903]: info: Command Router : Notfying DB Updatefalse Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:47 volacer volumio[903]: verbose: ControllerMpd::parseState Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: 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} Jul 02 15:42:47 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: No code Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: ControllerMpd::pushState Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::servicePushState Jul 02 15:42:47 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:47 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:47 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:48 volacer volumio[903]: 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} Jul 02 15:42:48 volacer volumio[903]: verbose: CURRENT POSITION 0 Jul 02 15:42:48 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop Jul 02 15:42:48 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop Jul 02 15:42:48 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:48 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:48 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:48 volacer volumio[903]: info: No code Jul 02 15:42:48 volacer volumio[903]: info: CoreStateMachine::pushState Jul 02 15:42:48 volacer volumio[903]: info: CorePlayQueue::getTrack 0 Jul 02 15:42:48 volacer volumio[903]: info: CoreCommandRouter::volumioPushState Jul 02 15:42:48 volacer volumio[903]: info: ------------------------------ 88ms Jul 02 15:42:48 volacer volumio[903]: info: ------------------------------ 91ms Jul 02 15:42:51 volacer volumio[903]: info: CD Rip Successfully started Jul 02 15:43:07 volacer sudo[21769]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr0 Jul 02 15:43:07 volacer sudo[21769]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 02 15:43:07 volacer sudo[21769]: pam_unix(sudo:session): session closed for user root Jul 02 15:43:07 volacer sudo[21772]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr1 Jul 02 15:43:07 volacer sudo[21772]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 02 15:43:07 volacer sudo[21772]: pam_unix(sudo:session): session closed for user root Jul 02 15:43:07 volacer volumio[903]: /bin/chmod: cannot access '/dev/sr1': No such file or directory Jul 02 15:43:07 volacer volumio[903]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jul 02 15:43:07 volacer volumio[903]: info: [1751470987217] CoreMusicLibrary::Adding element Audio CD Jul 02 15:43:07 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 02 15:43:07 volacer volumio[903]: Cannot find translation for source Audio CD Jul 02 15:43:12 volacer volumio[903]: info: Set CD Speed to 4X Jul 02 15:43:21 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , handleBrowseUri Jul 02 15:43:21 volacer volumio[903]: info: Preload queue cleared Jul 02 15:43:21 volacer volumio[903]: info: Executing endpoint getSimilarAlbums Jul 02 15:43:21 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jul 02 15:43:21 volacer volumio[903]: info: Executing endpoint metavolumio Jul 02 15:43:21 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 02 15:43:21 volacer volumio[903]: info: Executing endpoint metavolumio Jul 02 15:43:21 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jul 02 15:43:24 volacer volumio[903]: info: CALLMETHOD: music_service cd_controller getRipInfo Jul 02 15:43:24 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , getRipInfo Jul 02 15:43:24 volacer volumio[903]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 02 15:43:24 volacer volumio[903]: Error: ENOTCONN: socket is not connected, lstat '/mnt/USB/VOLUMIO' Jul 02 15:43:24 volacer volumio[903]: at Object.lstatSync (fs.js:1120:3) Jul 02 15:43:24 volacer volumio[903]: at Object.lstatSync (/volumio/node_modules/graceful-fs/polyfills.js:308:16) Jul 02 15:43:24 volacer volumio[903]: at /myvolumio/plugins/music_service/cd_controller/cd_controller_real:1:14222 Jul 02 15:43:24 volacer volumio[903]: at go$readdir$cb (/volumio/node_modules/graceful-fs/graceful-fs.js:195:14) Jul 02 15:43:24 volacer volumio[903]: at FSReqCallback.oncomplete (fs.js:180:23) { Jul 02 15:43:24 volacer volumio[903]: errno: -107, Jul 02 15:43:24 volacer volumio[903]: syscall: 'lstat', Jul 02 15:43:24 volacer volumio[903]: code: 'ENOTCONN', Jul 02 15:43:24 volacer volumio[903]: path: '/mnt/USB/VOLUMIO' Jul 02 15:43:24 volacer volumio[903]: } Jul 02 15:43:24 volacer volumio[903]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 02 15:43:24 volacer sudo[22766]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-02 15:42 Jul 02 15:43:24 volacer sudo[22766]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:07:11 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="dc77d77f02ef88ea816c3d31de871e8f"