Date: Wed, 2 Mar 2022 23:44:59 +0700 From: Eugene Grosbein <eugen@grosbein.net> To: Wojciech Puchar <wojtek@puchar.net> Cc: freebsd-hackers@freebsd.org Subject: Re: problem with USB-CD drive Message-ID: <2a3e46b6-3f93-bd7f-f6b2-bac2e3c6a1b2@grosbein.net> In-Reply-To: <50bcd532-934a-31f0-855e-d643417dd89@puchar.net> References: <197d435-6c4b-a60-4e6f-ea4ee515b8f4@puchar.net> <21050393-470a-8539-1324-3482d64c4870@grosbein.net> <50bcd532-934a-31f0-855e-d643417dd89@puchar.net>
next in thread | previous in thread | raw e-mail | index | archive | help
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.
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?2a3e46b6-3f93-bd7f-f6b2-bac2e3c6a1b2>