From nobody Thu Mar 03 21:03:19 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 299F319F3328 for ; Thu, 3 Mar 2022 21:03:23 +0000 (UTC) (envelope-from wojtek@puchar.net) Received: from puchar.net (puchar.net [194.1.144.90]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 4K8k3Z4Qwrz3Qd8 for ; Thu, 3 Mar 2022 21:03:22 +0000 (UTC) (envelope-from wojtek@puchar.net) Received: Received: from 127.0.0.1 (localhost [127.0.0.1]) by puchar.net (8.15.2/8.16.1) with ESMTPS id 223L3KRu012553 (version=TLSv1.2 cipher=ECDHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Thu, 3 Mar 2022 22:03:21 +0100 (CET) (envelope-from wojtek@puchar.net) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=puchar.net; s=default; t=1646341401; bh=TkeeVb5ozvoJD+IBTVGFeuy7nJ6aNbVF4W2XlBqGQrQ=; h=Date:From:To:cc:Subject:In-Reply-To:References; b=h8Zl+FnbDvNSDLSrXSI1TSUeM8YMqJCS6figXustnvmYyCyhJGiOzydzTq5VDNtEG MQpSI67mbxtdBpKFAQijSpm+epn/Y8WsnB4Oqw3FU7ON+VKWkRLrZgU6crN7WQwJQv IioYZNBwC4B37JLr3Ul/kCSqGWSidVefiFbV3ShM= Received: from wojtek.intra (localhost [127.0.0.1]) by wojtek.intra (8.16.1/8.16.1) with ESMTP id 223L3KLQ027033; Thu, 3 Mar 2022 22:03:20 +0100 (CET) (envelope-from wojtek@puchar.net) Received: from localhost (wojtek@localhost) by wojtek.intra (8.16.1/8.16.1/Submit) with ESMTP id 223L3JgJ027030; Thu, 3 Mar 2022 22:03:20 +0100 (CET) (envelope-from wojtek@puchar.net) X-Authentication-Warning: wojtek.intra: wojtek owned process doing -bs Date: Thu, 3 Mar 2022 22:03:19 +0100 (CET) From: Wojciech Puchar To: Eugene Grosbein cc: freebsd-hackers@freebsd.org Subject: Re: problem with USB-CD drive In-Reply-To: <2a3e46b6-3f93-bd7f-f6b2-bac2e3c6a1b2@grosbein.net> Message-ID: References: <197d435-6c4b-a60-4e6f-ea4ee515b8f4@puchar.net> <21050393-470a-8539-1324-3482d64c4870@grosbein.net> <50bcd532-934a-31f0-855e-d643417dd89@puchar.net> <2a3e46b6-3f93-bd7f-f6b2-bac2e3c6a1b2@grosbein.net> 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 Content-Type: text/plain; charset=US-ASCII; format=flowed X-Rspamd-Queue-Id: 4K8k3Z4Qwrz3Qd8 X-Spamd-Bar: --- Authentication-Results: mx1.freebsd.org; dkim=pass header.d=puchar.net header.s=default header.b=h8Zl+Fnb; dmarc=none; spf=pass (mx1.freebsd.org: domain of wojtek@puchar.net designates 194.1.144.90 as permitted sender) smtp.mailfrom=wojtek@puchar.net X-Spamd-Result: default: False [-3.50 / 15.00]; ARC_NA(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000]; R_DKIM_ALLOW(-0.20)[puchar.net:s=default]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; R_SPF_ALLOW(-0.20)[+mx:c]; NEURAL_HAM_LONG(-1.00)[-1.000]; MIME_GOOD(-0.10)[text/plain]; HAS_XAW(0.00)[]; DMARC_NA(0.00)[puchar.net]; RCVD_COUNT_THREE(0.00)[3]; TO_MATCH_ENVRCPT_SOME(0.00)[]; DKIM_TRACE(0.00)[puchar.net:+]; RCPT_COUNT_TWO(0.00)[2]; NEURAL_HAM_SHORT(-1.00)[-1.000]; MLMMJ_DEST(0.00)[freebsd-hackers]; FROM_EQ_ENVFROM(0.00)[]; MIME_TRACE(0.00)[0:+]; RCVD_TLS_LAST(0.00)[]; ASN(0.00)[asn:43476, ipnet:194.1.144.0/24, country:PL]; MID_RHS_MATCH_FROM(0.00)[] X-ThisMailContainsUnwantedMimeParts: N 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) >> 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. > > >