Re: r342378: usbconfig takes 3-5 minutes to read the bus
On 1/2/19 4:57 PM, Hans Petter Selasky wrote: On 1/2/19 4:47 PM, Matthias Apitz wrote: After card removal and insert devd(8) starts a new pcsd: Does pcsd install this devd(8) rule? I thought pcsd would no longer need to be restarted. > Let's move this thread freebsd-usb only. Have a look here: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=231076 --HPS ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
Re: r342378: usbconfig takes 3-5 minutes to read the bus
On 1/2/19 4:47 PM, Matthias Apitz wrote: After card removal and insert devd(8) starts a new pcsd: Does pcsd install this devd(8) rule? I thought pcsd would no longer need to be restarted. --HPS ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
Re: r342378: usbconfig takes 3-5 minutes to read the bus
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: at > > usbus1 > > Jan 2 11:25:39 c720-r342378 kernel: ugen1.2: > 0x8000> at usbus1 > > Jan 2 11:25:39 c720-r342378 kernel: ugen0.2: at > > usbus0 > > Jan 2 11:25:39 c720-r342378 kernel: ugen0.3: > 0xe056> at usbus0 > > Jan 2 11:25:39 c720-r342378 kernel: ugen0.4: > 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: 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 10242 / pcscd 13639 root rtd VDIR 0,113 10242 / 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,11398016 29294906 /usr/lib/libusb.so.3 pcscd 13639 root txt VREG 0,11327640 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 root0r VCHR 0,43 0t0 43 /dev/null pcscd 13639 root1u VCHR 0,43 0t0 43 /dev/null pcscd 13639 root2u VCHR 0,43 0t0 43 /dev/null pcscd 13639 root3u unix 0xf800609ff6d0 0t0 ->0xf800163fa368 pcscd 13639 root4u PIPE 0xf8004f13c2f816384 ->0xf8004f13c460 pcscd 13639 root5u PIPE 0xf8004f13c4600 ->0xf8004f13c2f8 pcscd 13639 root6u unix 0xf80072b03a38 0t0 /var/run/pcscd/pcscd.comm pcscd 13639 root7u PIPE 0xf8004e5422f816384 ->0xf8004e542460 pcscd 13639 root8u PIPE 0xf8004e5424600 ->0xf8004e5422f8 pcscd 13639 root9u PIPE 0xf8004e50900016384 ->0xf8004e509168 pcscd 13639 root 10u PIPE 0xf8004e5091680 ->0xf8004e509000 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 PIDTID COMMTDNAME 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, ✉ g...@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. ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
Re: r342378: usbconfig takes 3-5 minutes to read the bus
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 10242 / pcscd 501 root rtd VDIR 0,113 10242 / 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,11398016 29294906 /usr/lib/libusb.so.3 pcscd 501 root txt VREG 0,11327640 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 1905 /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/FreeBSD/libccid.so pcscd 501 root0r VCHR 0,43 0t0 43 /dev/null pcscd 501 root1u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root2u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root3u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root4u PIPE 0xf800162fd8e816384 ->0xf800162fda50 pcscd 501 root5u PIPE 0xf800162fda500 ->0xf800162fd8e8 pcscd 501 root6u unix 0xf800164036d0 0t0 /var/run/pcscd/pcscd.comm pcscd 501 root7u unix 0xf80016feaa38 0t0 /var/run/pcscd/pcscd.comm pcscd 501 root9u PIPE 0xf800162fd2f816384 ->0xf800162fd460, cnt=2, in=2 pcscd 501 root 10u PIPE 0xf800162fd4600 ->0xf800162fd2f8 pcscd 501 root 11u PIPE 0xf800162f28e816384 ->0xf800162f2a50 pcscd 501 root 12u PIPE 0xf800162f2a500 ->0xf800162f28e8 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 ...: D2760001240102010005532B Version ..: 2.1 Manufacturer .: ZeitControl Serial number : 532B 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 ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to
Re: r342378: usbconfig takes 3-5 minutes to read the bus
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 10242 / pcscd 501 root rtd VDIR 0,113 10242 / 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,11398016 29294906 /usr/lib/libusb.so.3 pcscd 501 root txt VREG 0,11327640 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 1905 /usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/FreeBSD/libccid.so pcscd 501 root0r VCHR 0,43 0t0 43 /dev/null pcscd 501 root1u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root2u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root3u VREG 0,113 3568882411580 / (/dev/ada0p2) pcscd 501 root4u PIPE 0xf800162fd8e816384 ->0xf800162fda50 pcscd 501 root5u PIPE 0xf800162fda500 ->0xf800162fd8e8 pcscd 501 root6u unix 0xf800164036d0 0t0 /var/run/pcscd/pcscd.comm pcscd 501 root7u unix 0xf80016feaa38 0t0 /var/run/pcscd/pcscd.comm pcscd 501 root9u PIPE 0xf800162fd2f816384 ->0xf800162fd460, cnt=2, in=2 pcscd 501 root 10u PIPE 0xf800162fd4600 ->0xf800162fd2f8 pcscd 501 root 11u PIPE 0xf800162f28e816384 ->0xf800162f2a50 pcscd 501 root 12u PIPE 0xf800162f2a500 ->0xf800162f28e8 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 ...: D2760001240102010005532B Version ..: 2.1 Manufacturer .: ZeitControl Serial number : 532B 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: 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 matthias -- Matthias Apitz, ✉ g...@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. signature.asc Description: PGP signature
Re: r342378: usbconfig takes 3-5 minutes to read the bus
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? Any error messages in dmesg? --HPS ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
r342378: usbconfig takes 3-5 minutes to read the bus
I updated my amd64 laptop Acer C720 from r314251 to r342378. The OpenPGP Card HID Global OMNIKEY 6121 was working in r314251 nicely and after withdraw and re-insert GnuPG was just asking for the PIN again and access to the ciphered material or signing keys was fine. 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. Please, what can I check or enable to get additional logs for the problem. Thanks # uname -a FreeBSD c720-r342378 13.0-CURRENT FreeBSD 13.0-CURRENT r342378 GENERIC amd64 # usbconfig list ugen1.1: at usbus1, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=SAVE (0mA) ugen0.1: <0x8086 XHCI root HUB> at usbus0, cfg=0 md=HOST spd=SUPER (5.0Gbps) pwr=SAVE (0mA) ugen0.2: at usbus0, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=ON (500mA) ugen1.2: at usbus1, cfg=0 md=HOST spd=HIGH (480Mbps) pwr=SAVE (0mA) ugen0.3: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) # usbconfig -d ugen0.4 list ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) # usbconfig -d ugen0.4 dump_device_desc ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x bDeviceSubClass = 0x bDeviceProtocol = 0x bMaxPacketSize0 = 0x0008 idVendor = 0x076b idProduct = 0x6632 bcdDevice = 0x0103 iManufacturer = 0x0001 iProduct = 0x0002 iSerialNumber = 0x bNumConfigurations = 0x0001 From now it takes 3++ minutes to get the information from USB: # date ; usbconfig -d ugen0.4 dump_device_desc ; date Tue Jan 1 11:51:55 CET 2019 ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x bDeviceSubClass = 0x bDeviceProtocol = 0x bMaxPacketSize0 = 0x0008 idVendor = 0x076b idProduct = 0x6632 bcdDevice = 0x0103 iManufacturer = 0x0001 iProduct = 0x0002 iSerialNumber = 0x bNumConfigurations = 0x0001 Tue Jan 1 11:54:59 CET 2019 # date ; usbconfig -d ugen0.4 dump_device_desc ; date Tue Jan 1 14:30:19 CET 2019 ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x bDeviceSubClass = 0x bDeviceProtocol = 0x bMaxPacketSize0 = 0x0008 idVendor = 0x076b idProduct = 0x6632 bcdDevice = 0x0103 iManufacturer = 0x0001 iProduct = 0x0002 iSerialNumber = 0x bNumConfigurations = 0x0001 Tue Jan 1 14:34:05 CET 2019 # tail -f /var/log/messages ... Jan 1 14:34:30 c720-r342378 kernel: ugen0.4: at usbus0 (disconnected) Jan 1 14:34:36 c720-r342378 kernel: ugen0.4: at usbus0 # date ; usbconfig -d ugen0.4 dump_device_desc ; date Tue Jan 1 14:34:46 CET 2019 ugen0.4: at usbus0, cfg=0 md=HOST spd=FULL (12Mbps) pwr=ON (100mA) bLength = 0x0012 bDescriptorType = 0x0001 bcdUSB = 0x0200 bDeviceClass = 0x bDeviceSubClass = 0x bDeviceProtocol = 0x bMaxPacketSize0 = 0x0008 idVendor = 0x076b idProduct = 0x6632 bcdDevice = 0x0103 iManufacturer = 0x0001 iProduct = 0x0002 iSerialNumber = 0x bNumConfigurations = 0x0001 Tue Jan 1 14:39:13 CET 2019 -- Matthias Apitz, ✉ g...@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. ___ freebsd-current@freebsd.org mailing list https://lists.freebsd.org/mailman/listinfo/freebsd-current To unsubscribe, send any mail to "freebsd-current-unsubscr...@freebsd.org"
