-- Logs begin at Mon 2025-05-12 08:15:49 UTC, end at Mon 2025-05-12 13:33:57 UTC. -- May 12 13:33:17 volacer sudo[16764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr0 May 12 13:33:17 volacer sudo[16764]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 13:33:17 volacer sudo[16764]: pam_unix(sudo:session): session closed for user root May 12 13:33:17 volacer sudo[16767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /dev/sr1 May 12 13:33:17 volacer sudo[16767]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 13:33:17 volacer sudo[16767]: pam_unix(sudo:session): session closed for user root May 12 13:33:17 volacer volumio[903]: /bin/chmod: cannot access '/dev/sr1': No such file or directory May 12 13:33:17 volacer volumio[903]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 12 13:33:17 volacer volumio[903]: info: [1747056797398] CoreMusicLibrary::Adding element Audio CD May 12 13:33:17 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 12 13:33:17 volacer volumio[903]: Cannot find translation for source Audio CD May 12 13:33:17 volacer kernel: usb 3-4: USB disconnect, device number 2 May 12 13:33:18 volacer volumio[903]: info: Partition removed: {"syspath":"/sys/devices/pci0000:00/0000:00:1d.7/usb3/3-4/3-4:1.0/host7/target7:0:0/7:0:0:0/block/sdd/sdd1","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:4:1.0-scsi-0:0:0:0-part1 /dev/disk/by-uuid/E0CB-D669 /dev/disk/by-partuuid/bd27ec4c-01","DEVNAME":"/dev/sdd1","DEVPATH":"/devices/pci0000:00/0000:00:1d.7/usb3/3-4/3-4:1.0/host7/target7:0:0/7:0:0:0/block/sdd/sdd1","DEVTYPE":"partition","DISKSEQ":"6","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:48","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:4:1.0-scsi-0:0:0:0","ID_PATH_TAG":"pci-0000_00_1d_7-usb-0_4_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":"49","PARTN":"1","SEQNUM":"3239","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"3675662"} May 12 13:33:18 volacer kernel: sd 7:0:0:0: [sdd] Synchronizing SCSI cache May 12 13:33:18 volacer sudo[16920]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sdd1 May 12 13:33:18 volacer sudo[16920]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 13:33:18 volacer sudo[16920]: pam_unix(sudo:session): session closed for user root May 12 13:33:18 volacer volumio[903]: umount: /media/VOLUMIO: target is busy. May 12 13:33:18 volacer volumio[903]: error: Failed to umount VOLUMIO: Error: Command failed: /usr/bin/sudo /bin/umount -f "/dev/sdd1" May 12 13:33:18 volacer volumio[903]: umount: /media/VOLUMIO: target is busy. May 12 13:33:18 volacer mount.exfat[1156]: non-zero reference counter (1) for '5.Faced_With_Complete_Failure,_Utter_Defiance_Is_the_Only_Response.flac' May 12 13:33:18 volacer mount.exfat[1156]: failed to write super block May 12 13:33:18 volacer kernel: sd 7:0:0:0: [sdd] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK May 12 13:33:20 volacer kernel: usb 3-3: new high-speed USB device number 5 using ehci-pci May 12 13:33:20 volacer kernel: usb 3-3: New USB device found, idVendor=0dd8, idProduct=3908, bcdDevice= 2.06 May 12 13:33:20 volacer kernel: usb 3-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3 May 12 13:33:20 volacer kernel: usb 3-3: Product: DISK 3.2 May 12 13:33:20 volacer kernel: usb 3-3: Manufacturer: Netac May 12 13:33:20 volacer kernel: usb 3-3: SerialNumber: DD56419884345 May 12 13:33:20 volacer kernel: scsi host8: uas May 12 13:33:20 volacer kernel: scsi 8:0:0:0: Direct-Access Netac DISK 3.2 0206 PQ: 0 ANSI: 6 May 12 13:33:20 volacer kernel: sd 8:0:0:0: Attached scsi generic sg4 type 0 May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] 1000215216 512-byte logical blocks: (512 GB/477 GiB) May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] 4096-byte physical blocks May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Write Protect is off May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Mode Sense: 5f 00 00 08 May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Preferred minimum I/O size 4096 bytes May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Optimal transfer size 33553920 bytes not a multiple of preferred minimum block size (4096 bytes) May 12 13:33:21 volacer kernel: sde: sde1 May 12 13:33:21 volacer kernel: sd 8:0:0:0: [sde] Attached SCSI disk May 12 13:33:22 volacer volumio[903]: info: Mounting Device VOLUMIO May 12 13:33:22 volacer volumio[903]: /bin/mkdir: cannot create directory ‘/mnt/USB/VOLUMIO’: File exists May 12 13:33:22 volacer volumio[903]: error: Failed to create folder Error: Command failed: /bin/mkdir -m 777 "/mnt/USB/VOLUMIO" May 12 13:33:22 volacer volumio[903]: /bin/mkdir: cannot create directory ‘/mnt/USB/VOLUMIO’: File exists May 12 13:33:22 volacer sudo[17582]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sde1 /mnt/USB/VOLUMIO -o noatime May 12 13:33:22 volacer sudo[17582]: pam_unix(sudo:session): session opened for user root by (uid=0) May 12 13:33:22 volacer mount.exfat[17584]: volume was not unmounted cleanly May 12 13:33:22 volacer sudo[17582]: pam_unix(sudo:session): session closed for user root May 12 13:33:22 volacer volumio[903]: WARN: volume was not unmounted cleanly. May 12 13:33:22 volacer volumio[903]: fuse: bad mount point `/mnt/USB/VOLUMIO': Transport endpoint is not connected May 12 13:33:22 volacer volumio[903]: error: Failed to mount VOLUMIO: Error: Command failed: /usr/bin/sudo /bin/mount "/dev/sde1" "/mnt/USB/VOLUMIO" -o noatime May 12 13:33:22 volacer volumio[903]: WARN: volume was not unmounted cleanly. May 12 13:33:22 volacer volumio[903]: fuse: bad mount point `/mnt/USB/VOLUMIO': Transport endpoint is not connected May 12 13:33:22 volacer volumio[903]: info: Set CD Speed to 4X May 12 13:33:23 volacer volumio[903]: info: Scanning removed location : "USB/VOLUMIO" May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status May 12 13:33:23 volacer volumio[903]: info: May 12 13:33:23 volacer volumio[903]: ---------------------------- MPD announces state update: update May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::getState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status May 12 13:33:23 volacer volumio[903]: info: MPD Database updated - AlbumList cache refreshed May 12 13:33:23 volacer volumio[903]: info: May 12 13:33:23 volacer volumio[903]: ---------------------------- MPD announces state update: database May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status May 12 13:33:23 volacer volumio[903]: info: May 12 13:33:23 volacer volumio[903]: ---------------------------- MPD announces state update: update May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::getState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::getState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand status May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand status took 3 milliseconds May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand status took 2 milliseconds May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseState May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4096, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4097, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4098, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4099, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4100, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4101, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4102, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4103, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4104, lost async page write May 12 13:33:23 volacer kernel: Buffer I/O error on dev sdd1, logical block 4105, lost async page write May 12 13:33:23 volacer volumio[903]: info: Command Router : Notfying DB Updatefalse May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand status took 31 milliseconds May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseState May 12 13:33:23 volacer volumio[903]: info: Command Router : Notfying DB Updatefalse May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::Close All Modals sent May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand status took 49 milliseconds May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand status took 51 milliseconds May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand playlistinfo took 28 milliseconds May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseState May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseTrackInfo May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::pushState May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::servicePushState May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3","artist":null,"album":null,"uri":"cdda:///3","trackType":"CD Audio"} May 12 13:33:23 volacer volumio[903]: verbose: CURRENT POSITION 0 May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: No code May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: ------------------------------ 62ms May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand playlistinfo took 22 milliseconds May 12 13:33:23 volacer volumio[903]: info: sendMpdCommand playlistinfo took 22 milliseconds May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseTrackInfo May 12 13:33:23 volacer volumio[903]: verbose: ControllerMpd::parseTrackInfo May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::pushState May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::servicePushState May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3","artist":null,"album":null,"uri":"cdda:///3","trackType":"CD Audio"} May 12 13:33:23 volacer volumio[903]: verbose: CURRENT POSITION 0 May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: No code May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: ControllerMpd::pushState May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::servicePushState May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"3","artist":null,"album":null,"uri":"cdda:///3","trackType":"CD Audio"} May 12 13:33:23 volacer volumio[903]: verbose: CURRENT POSITION 0 May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState stateService stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::syncState currentStatus stop May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: No code May 12 13:33:23 volacer volumio[903]: info: CoreStateMachine::pushState May 12 13:33:23 volacer volumio[903]: info: CorePlayQueue::getTrack 0 May 12 13:33:23 volacer volumio[903]: info: CoreCommandRouter::volumioPushState May 12 13:33:23 volacer volumio[903]: info: ------------------------------ 90ms May 12 13:33:23 volacer volumio[903]: info: ------------------------------ 92ms May 12 13:33:42 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , handleBrowseUri May 12 13:33:42 volacer volumio[903]: info: Preload queue cleared May 12 13:33:52 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , handleBrowseUri May 12 13:33:52 volacer volumio[903]: info: Preload queue cleared May 12 13:33:57 volacer volumio[903]: info: CALLMETHOD: music_service cd_controller getRipInfo May 12 13:33:57 volacer volumio[903]: info: CoreCommandRouter::executeOnPlugin: cd_controller , getRipInfo May 12 13:33:57 volacer volumio[903]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 13:33:57 volacer volumio[903]: Error: ENOTCONN: socket is not connected, lstat '/mnt/USB/VOLUMIO' May 12 13:33:57 volacer volumio[903]: at Object.lstatSync (fs.js:1120:3) May 12 13:33:57 volacer volumio[903]: at Object.lstatSync (/volumio/node_modules/graceful-fs/polyfills.js:308:16) May 12 13:33:57 volacer volumio[903]: at /myvolumio/plugins/music_service/cd_controller/cd_controller_real:1:14222 May 12 13:33:57 volacer volumio[903]: at go$readdir$cb (/volumio/node_modules/graceful-fs/graceful-fs.js:195:14) May 12 13:33:57 volacer volumio[903]: at FSReqCallback.oncomplete (fs.js:180:23) { May 12 13:33:57 volacer volumio[903]: errno: -107, May 12 13:33:57 volacer volumio[903]: syscall: 'lstat', May 12 13:33:57 volacer volumio[903]: code: 'ENOTCONN', May 12 13:33:57 volacer volumio[903]: path: '/mnt/USB/VOLUMIO' May 12 13:33:57 volacer volumio[903]: } May 12 13:33:57 volacer volumio[903]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 12 13:33:57 volacer sudo[17652]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-12 13:32 May 12 13:33:57 volacer sudo[17652]: 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"