From nobody Wed Mar 02 16:44:59 2022 X-Original-To: freebsd-hackers@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id D2F8319F0A80 for ; Wed, 2 Mar 2022 16:45:35 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from hz.grosbein.net (hz.grosbein.net [IPv6:2a01:4f8:c2c:26d8::2]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "hz.grosbein.net", Issuer "hz.grosbein.net" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 4K80NZ6qX2z4QlM for ; Wed, 2 Mar 2022 16:45:34 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from eg.sd.rdtc.ru (root@eg.sd.rdtc.ru [62.231.161.221] (may be forged)) by hz.grosbein.net (8.15.2/8.15.2) with ESMTPS id 222GjUhb023532 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NOT); Wed, 2 Mar 2022 16:45:31 GMT (envelope-from eugen@grosbein.net) X-Envelope-From: eugen@grosbein.net X-Envelope-To: wojtek@puchar.net Received: from [10.58.0.11] ([10.58.0.11]) by eg.sd.rdtc.ru (8.16.1/8.16.1) with ESMTPS id 222Gj496063927 (version=TLSv1.2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128 verify=NOT); Wed, 2 Mar 2022 23:45:29 +0700 (+07) (envelope-from eugen@grosbein.net) Subject: Re: problem with USB-CD drive To: Wojciech Puchar References: <197d435-6c4b-a60-4e6f-ea4ee515b8f4@puchar.net> <21050393-470a-8539-1324-3482d64c4870@grosbein.net> <50bcd532-934a-31f0-855e-d643417dd89@puchar.net> Cc: freebsd-hackers@freebsd.org From: Eugene Grosbein Message-ID: <2a3e46b6-3f93-bd7f-f6b2-bac2e3c6a1b2@grosbein.net> Date: Wed, 2 Mar 2022 23:44:59 +0700 User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:45.0) Gecko/20100101 Thunderbird/45.8.0 List-Id: Technical discussions relating to FreeBSD List-Archive: https://lists.freebsd.org/archives/freebsd-hackers List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-freebsd-hackers@freebsd.org MIME-Version: 1.0 In-Reply-To: <50bcd532-934a-31f0-855e-d643417dd89@puchar.net> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=-1.0 required=5.0 tests=ALL_TRUSTED,SHORTCIRCUIT autolearn=disabled version=3.4.2 X-Spam-Report: * -0.0 SHORTCIRCUIT No description available. * -1.0 ALL_TRUSTED Passed through trusted hosts only via SMTP X-Spam-Checker-Version: SpamAssassin 3.4.2 (2018-09-13) on hz.grosbein.net X-Rspamd-Queue-Id: 4K80NZ6qX2z4QlM X-Spamd-Bar: -- Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=fail (mx1.freebsd.org: domain of eugen@grosbein.net does not designate 2a01:4f8:c2c:26d8::2 as permitted sender) smtp.mailfrom=eugen@grosbein.net X-Spamd-Result: default: False [-2.10 / 15.00]; ARC_NA(0.00)[]; R_SPF_FAIL(1.00)[-all]; FREEFALL_USER(0.00)[eugen]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-0.997]; NEURAL_HAM_LONG(-1.00)[-0.999]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[grosbein.net]; RCVD_COUNT_THREE(0.00)[3]; TO_MATCH_ENVRCPT_SOME(0.00)[]; NEURAL_HAM_SHORT(-1.00)[-0.999]; RCPT_COUNT_TWO(0.00)[2]; MLMMJ_DEST(0.00)[freebsd-hackers]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:24940, ipnet:2a01:4f8::/32, country:DE]; RCVD_TLS_ALL(0.00)[]; MID_RHS_MATCH_FROM(0.00)[] X-ThisMailContainsUnwantedMimeParts: N 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) > 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,0x1002,0xffffffff,0) > 847 mount_cd9660 RET mmap 34376515584/0x801000000 > 847 mount_cd9660 CALL nmount(0x801015080,0x8,0x1) > 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.