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

[Matthias Apitz]

El día miércoles, enero 02, 2019 a las 12:37:37p. m. +0100, Hans Petter Selasky escribió:

> > Nothing. Only on boot it sees the card:
> 
> And you are using the latest version of pcsd ?

Yes. Compiled with all ports from December 23.

> 
> > 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
> 
> There has been some changes in libusb recently .

After card removal and insert devd(8) starts a new pcsd:

Jan  2 16:39:11 c720-r342378 kernel: ugen0.4: <Identiv uTrust 3512 SAM slot Token> at usbus0
Jan  2 16:39:11 c720-r342378 root[13636]: CCID uTrust, type: ATTACH, system: USB, subsystem: INTERFACE
Jan  2 16:39:11 c720-r342378 root[13637]: /usr/local/sbin/pcscd --debug --foreground

This sits hanging on /dev/usb/1.1.0:

# lsof -p 13639
COMMAND   PID USER   FD   TYPE             DEVICE SIZE/OFF     NODE NAME
pcscd   13639 root  cwd   VDIR              0,113     1024        2 /
pcscd   13639 root  rtd   VDIR              0,113     1024        2 /
pcscd   13639 root  txt   VREG              0,113   121992 15279826 /usr/local/sbin/pcscd
pcscd   13639 root  txt   VREG              0,113   151560 29294355 /libexec/ld-elf.so.1
pcscd   13639 root  txt   VREG              0,113    98016 29294906 /usr/lib/libusb.so.3
pcscd   13639 root  txt   VREG              0,113    27640 29294864 /usr/lib/librt.so.1
pcscd   13639 root  txt   VREG              0,113   135712 29293769 /lib/libthr.so.3
pcscd   13639 root  txt   VREG              0,113  2063072 29294412 /lib/libc.so.7
pcscd   13639 root    0r  VCHR               0,43      0t0       43 /dev/null
pcscd   13639 root    1u  VCHR               0,43      0t0       43 /dev/null
pcscd   13639 root    2u  VCHR               0,43      0t0       43 /dev/null
pcscd   13639 root    3u  unix 0xfffff800609ff6d0      0t0          ->0xfffff800163fa368
pcscd   13639 root    4u  PIPE 0xfffff8004f13c2f8    16384          ->0xfffff8004f13c460
pcscd   13639 root    5u  PIPE 0xfffff8004f13c460        0          ->0xfffff8004f13c2f8
pcscd   13639 root    6u  unix 0xfffff80072b03a38      0t0          /var/run/pcscd/pcscd.comm
pcscd   13639 root    7u  PIPE 0xfffff8004e5422f8    16384          ->0xfffff8004e542460
pcscd   13639 root    8u  PIPE 0xfffff8004e542460        0          ->0xfffff8004e5422f8
pcscd   13639 root    9u  PIPE 0xfffff8004e509000    16384          ->0xfffff8004e509168
pcscd   13639 root   10u  PIPE 0xfffff8004e509168        0          ->0xfffff8004e509000
pcscd   13639 root   11u  VCHR               0,52      0t0       52 /dev/usb/1.1.0
pcscd   13639 root   12u  VCHR               0,52      0t0       52 /dev/usb/1.1.0

(note: the older working proc had open /dev/usb/0.4.0)

> What does "procstat -ak" output. Does it hang on any "usb" functions?

# ps ax | grep pcs
13639  -  I      0:00,01 /usr/local/sbin/pcscd --debug --foreground
13967  4  S+     0:00,01 grep pcs

# procstat -k 13639
  PID    TID COMM                TDNAME              KSTACK
13639 100287 pcscd               -                   mi_switch sleepq_switch sleepq_catch_signals sleepq_wait_sig _sleep pipe_read dofileread kern_readv sys_read amd64_syscall fast_syscall_common
13639 100821 pcscd               -                   mi_switch sleepq_switch sleepq_catch_signals sleepq_wait_sig _sleep pipe_read dofileread kern_readv sys_read amd64_syscall fast_syscall_common
13639 100822 pcscd               -                   mi_switch sleepq_switch sleepq_catch_signals sleepq_wait_sig _sx_xlock_hard _sx_xlock usbd_enum_lock_sig usb_ref_device usb_open devfs_open VOP_OPEN_APV vn_open_vnode vn_open_cred kern_openat amd64_syscall fast_syscall_common

	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.