Re: problem with USB-CD drive

From: Wojciech Puchar <wojtek_at_puchar.net>
Date: Thu, 03 Mar 2022 21:03:19 UTC
will do next week

On Wed, 2 Mar 2022, Eugene Grosbein wrote:

> 02.03.2022 16:07, Wojciech Puchar wrote:
>
>>> It looks like the device or driver do not like size of reading request,
>>> f.e. short read. It should be possible to verify that using several ways:
>>> 1) run "ktrace -i mount_cd9660 ..." then study ouput of kdump;
>>    847 mount_cd9660 STRU  struct stat {dev=156, ino=261120, mode=040755, nlink=2, uid=0, gid=0, rdev=2085752, atime=1581328619, mtime=15
>> 81328630.081523000, ctime=1581328648.345917000, birthtime=315532800, size=1024, blksize=32768, blocks=8, flags=0x0 }
>>    847 mount_cd9660 RET   lstat 0
>>    847 mount_cd9660 CALL  stat(0x7fffffffe440,0x7fffffffe3a0)
>>    847 mount_cd9660 NAMI  "/mnt"
>>    847 mount_cd9660 STRU  struct stat {dev=156, ino=261120, mode=040755, nlink=2, uid=0, gid=0, rdev=2085752, atime=1581328619, mtime=15
>> 81328630.081523000, ctime=1581328648.345917000, birthtime=315532800, size=1024, blksize=32768, blocks=8, flags=0x0 }
>>    847 mount_cd9660 RET   stat 0
>>    847 mount_cd9660 CALL  openat(AT_FDCWD,0x7fffffffee6d,0<O_RDONLY>)
>>    847 mount_cd9660 NAMI  "/dev/cd1"
>>    847 mount_cd9660 RET   openat 3
>>    847 mount_cd9660 CALL  ioctl(0x3,CDIOREADTOCHEADER,0x7fffffffeb88)
>>    847 mount_cd9660 RET   ioctl 0
>>    847 mount_cd9660 CALL  ioctl(0x3,CDIOREADTOCENTRYS,0x7fffffffeb60)
>>    847 mount_cd9660 RET   ioctl 0
>>    847 mount_cd9660 CALL  close(0x3)
>>    847 mount_cd9660 RET   close 0
>>    847 mount_cd9660 CALL mmap(0,0x200000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,0xffffffff,0)
>>    847 mount_cd9660 RET   mmap 34376515584/0x801000000
>>    847 mount_cd9660 CALL  nmount(0x801015080,0x8,0x1<MNT_RDONLY>)
>>    847 mount_cd9660 NAMI  "/mnt"
>>    847 mount_cd9660 NAMI  "/mnt"
>>    847 mount_cd9660 NAMI  "/dev/cd1"
>>    847 mount_cd9660 RET   nmount -1 errno 22 Invalid argument
>> could you please help me to understand this?
>> is it something about CDIOREADTOCHEADER and CDIOREADTOCENTRYS returning not what it should return?
>
> No. We see here that at user level the sequence breaks on nmount system call.
> There is no more details but we may assume that nmount leads to short reads inside the kernel land (and breaks).
>
>>> 2) enable debug logs at GEOM level, use sysctl kern.geom.debugflags=255
>>> (beware of large amount of logs) then run mount_cd9660
>>> 3) use gcache(8) that is capable of limiting minimum request size by caching "extra" data,
>>> but try using only single gcache(8) instance per system because of known instability in the gcache code
>>> when you create multiple geom_cache's.
>>>
>> did gcache with 2kB blocks. works fine. Seems like a problem is here - some requests are not handled.
>>
>> now i tested reading it with dd with 2,4,8,16 and 32kB blocks. seems fine.
>>
>> trying to read with blocks like 1k, 512 doesn't work but it is i think normal - CDs have 2kB blocks.
>>
>> real CD drive behaves the same way.
>
> It's time to enable geom logs to look at size of read requests going to low level driver.
>
>
>