From owner-freebsd-usb@freebsd.org Wed Jan 2 11:40:00 2019 Return-Path: Delivered-To: freebsd-usb@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id C95FF1440866; Wed, 2 Jan 2019 11:40:00 +0000 (UTC) (envelope-from hps@selasky.org) Received: from mail.turbocat.net (turbocat.net [IPv6:2a01:4f8:c17:6c4b::2]) (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 9ABFF883AC; Wed, 2 Jan 2019 11:39:59 +0000 (UTC) (envelope-from hps@selasky.org) Received: from hps2016.home.selasky.org (unknown [176.74.212.121]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by mail.turbocat.net (Postfix) with ESMTPSA id F40B0260359; Wed, 2 Jan 2019 12:39:56 +0100 (CET) Subject: Re: r342378: usbconfig takes 3-5 minutes to read the bus To: freebsd-current@freebsd.org, freebsd-usb@freebsd.org References: <20190101135156.GA3557@c720-r342378> <3ac801b2-899a-ee09-1398-ecab6ec7130a@selasky.org> <20190102104853.GA2622@c720-r342378> From: Hans Petter Selasky Message-ID: <4bf80067-8e3a-572f-c1b5-ae83b1c40c22@selasky.org> Date: Wed, 2 Jan 2019 12:37:37 +0100 User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:60.0) Gecko/20100101 Thunderbird/60.4.0 MIME-Version: 1.0 In-Reply-To: <20190102104853.GA2622@c720-r342378> Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US Content-Transfer-Encoding: 8bit X-Rspamd-Queue-Id: 9ABFF883AC X-Spamd-Bar: ------ Authentication-Results: mx1.freebsd.org; spf=pass (mx1.freebsd.org: domain of hps@selasky.org designates 2a01:4f8:c17:6c4b::2 as permitted sender) smtp.mailfrom=hps@selasky.org X-Spamd-Result: default: False [-6.15 / 15.00]; ARC_NA(0.00)[]; RCVD_VIA_SMTP_AUTH(0.00)[]; NEURAL_HAM_MEDIUM(-1.00)[-1.000,0]; FROM_HAS_DN(0.00)[]; R_SPF_ALLOW(-0.20)[+a:mail.turbocat.net]; TO_MATCH_ENVRCPT_ALL(0.00)[]; MIME_GOOD(-0.10)[text/plain]; TO_DN_NONE(0.00)[]; DMARC_NA(0.00)[selasky.org]; NEURAL_HAM_LONG(-1.00)[-1.000,0]; IP_SCORE(-2.85)[ip: (-9.05), ipnet: 2a01:4f8::/29(-2.75), asn: 24940(-2.43), country: DE(-0.01)]; MX_GOOD(-0.01)[cached: mail.turbocat.net]; RCPT_COUNT_TWO(0.00)[2]; NEURAL_HAM_SHORT(-0.99)[-0.988,0]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:24940, ipnet:2a01:4f8::/29, country:DE]; MID_RHS_MATCH_FROM(0.00)[]; RCVD_TLS_ALL(0.00)[]; RCVD_COUNT_TWO(0.00)[2] X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 02 Jan 2019 11:40:01 -0000 On 1/2/19 11:48 AM, Matthias Apitz wrote: > El día miércoles, enero 02, 2019 a las 09:44:06a. m. +0100, Hans Petter Selasky escribió: > >> On 1/1/19 2:51 PM, Matthias Apitz wrote: >>> Now with r342378, it works only after boot but not after withdraw/re-insert >>> anymore. To separate the problem from GnuPG and it's software stack, I have here some >>> small tests with usbconfig(8). First usbconfig reads fine the bus, but then >>> it takes 3-5 minutes to get any results, see below. >> >> Did you update the user-space libusb aswell? > > I did a complete 'make installworld' and they look updated: > > $ ls -l /usr/lib/libusb* > -r--r--r-- 1 root wheel 573256 31 dic. 12:19 /usr/lib/libusb_p.a > -r--r--r-- 1 root wheel 541506 31 dic. 12:19 /usr/lib/libusb.a > lrwxr-xr-x 1 root wheel 11 31 dic. 12:33 /usr/lib/libusb.so -> libusb.so.3 > -r--r--r-- 1 root wheel 98016 31 dic. 12:33 /usr/lib/libusb.so.3 > -r--r--r-- 1 root wheel 73910 31 dic. 12:19 /usr/lib/libusbhid_p.a > -r--r--r-- 1 root wheel 71390 31 dic. 12:19 /usr/lib/libusbhid.a > lrwxr-xr-x 1 root wheel 14 31 dic. 12:33 /usr/lib/libusbhid.so -> libusbhid.so.4 > -r--r--r-- 1 root wheel 23720 31 dic. 12:33 /usr/lib/libusbhid.so.4 > > At boot time a process is launched by devd(8) which reads the OpenPGP > card and this works fine and has the device open: > > $ ps ax | grep pcs > 501 v0- S 0:00,22 /usr/local/sbin/pcscd --debug --foreground > > # lsof -p 501 > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME > pcscd 501 root cwd VDIR 0,113 1024 2 / > pcscd 501 root rtd VDIR 0,113 1024 2 / > pcscd 501 root txt VREG 0,113 121992 15279826 /usr/local/sbin/pcscd > pcscd 501 root txt VREG 0,113 151560 29294355 /libexec/ld-elf.so.1 > pcscd 501 root txt VREG 0,113 98016 29294906 /usr/lib/libusb.so.3 > pcscd 501 root txt VREG 0,113 27640 29294864 /usr/lib/librt.so.1 > pcscd 501 root txt VREG 0,113 135712 29293769 /lib/libthr.so.3 > pcscd 501 root txt VREG 0,113 2063072 29294412 /lib/libc.so.7 > pcscd 501 root txt VREG 0,113 135192 19033335 /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/FreeBSD/libccid.so > pcscd 501 root 0r VCHR 0,43 0t0 43 /dev/null > pcscd 501 root 1u VREG 0,113 35688824 11580 / (/dev/ada0p2) > pcscd 501 root 2u VREG 0,113 35688824 11580 / (/dev/ada0p2) > pcscd 501 root 3u VREG 0,113 35688824 11580 / (/dev/ada0p2) > pcscd 501 root 4u PIPE 0xfffff800162fd8e8 16384 ->0xfffff800162fda50 > pcscd 501 root 5u PIPE 0xfffff800162fda50 0 ->0xfffff800162fd8e8 > pcscd 501 root 6u unix 0xfffff800164036d0 0t0 /var/run/pcscd/pcscd.comm > pcscd 501 root 7u unix 0xfffff80016feaa38 0t0 /var/run/pcscd/pcscd.comm > pcscd 501 root 9u PIPE 0xfffff800162fd2f8 16384 ->0xfffff800162fd460, cnt=2, in=2 > pcscd 501 root 10u PIPE 0xfffff800162fd460 0 ->0xfffff800162fd2f8 > pcscd 501 root 11u PIPE 0xfffff800162f28e8 16384 ->0xfffff800162f2a50 > pcscd 501 root 12u PIPE 0xfffff800162f2a50 0 ->0xfffff800162f28e8 > pcscd 501 root 13u VCHR 0,87 0t0 87 /dev/usb/0.4.0 > pcscd 501 root 14u VCHR 0,87 0t0 87 /dev/usb/0.4.0 > > $ gpg2 --card-status > Reader ...........: Identiv uTrust 3512 SAM slot Token (55511725600891) 00 00 > Application ID ...: D27600012401020100050000532B0000 > Version ..........: 2.1 > Manufacturer .....: ZeitControl > Serial number ....: 0000532B > Name of cardholder: Matthias Apitz > ... > > > When I withdraw the OpenPGP card devd(8) hooks kill that proc and > restarts a new one on card insert. But this new proc hangs. > > The same happens when I disable the devd(8) start of this proc and start > the same proc from a shell (for debugging). This hangs too. > > Looks like something makes the USB stack broken after the point where > devd(8) can launch fine the first proc of pcscd. > >> Any error messages in dmesg? > Hi, > Nothing. Only on boot it sees the card: And you are using the latest version of pcsd ? > Jan 2 11:25:39 c720-r342378 kernel: ugen0.1: <0x8086 XHCI root HUB> at usbus0 > Jan 2 11:25:39 c720-r342378 kernel: ugen1.1: at usbus1 > Jan 2 11:25:39 c720-r342378 kernel: ugen1.2: at usbus1 > Jan 2 11:25:39 c720-r342378 kernel: ugen0.2: at usbus0 > Jan 2 11:25:39 c720-r342378 kernel: ugen0.3: at usbus0 > Jan 2 11:25:39 c720-r342378 kernel: ugen0.4: at usbus0 There has been some changes in libusb recently . What does "procstat -ak" output. Does it hang on any "usb" functions? --HPS