r342378: usbconfig takes 3-5 minutes to read the bus

[Matthias Apitz]

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?

Nothing. Only on boot it sees the card:

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: <Intel EHCI root HUB> at usbus1
Jan  2 11:25:39 c720-r342378 kernel: ugen1.2: <vendor 0x8087 product 0x8000> at usbus1
Jan  2 11:25:39 c720-r342378 kernel: ugen0.2: <SunplusIT Inc HD WebCam> at usbus0
Jan  2 11:25:39 c720-r342378 kernel: ugen0.3: <vendor 0x0489 product 0xe056> at usbus0
Jan  2 11:25:39 c720-r342378 kernel: ugen0.4: <Identiv uTrust 3512 SAM slot Token> at usbus0

	matthias

-- 
Matthias Apitz, ✉ guru at unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
October, 7 -- The GDR was different: Peace instead of Bundeswehr and wars, Druschba
instead of Nazis, to live instead of to survive.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: not available
URL: <http://lists.freebsd.org/pipermail/freebsd-usb/attachments/20190102/1a89734b/attachment.sig>