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

2019-04-02 Thread Matthias Apitz 
El día viernes, enero 04, 2019 a las 10:09:27p. m. +0100, Hans Petter Selasky 
escribió:

> On 1/4/19 7:31 PM, Matthias Apitz wrote:
> > El día viernes, enero 04, 2019 a las 07:02:16p. m. +0100, Hans Petter 
> > Selasky escribió:
> > 
> >> On 1/4/19 7:03 PM, Matthias Apitz wrote:
> >>> I've applied the 2nd patch on the already patched sources, it fails.
> >>> Should I use the original sources without your first patch?
> >>
> >> You should revert all prior patches.
> > 
> > Done. Please find attached the messages. I did 'usbconfig list' and this
> > is marked with this string in the messages.
> 
> The attached log looks good. I assume the patch still fixes your issue - 
> right?
> 
> https://svnweb.freebsd.org/changeset/base/342778


My son runs the same hardware Acer C720 with an older 12-CURRENT:

$ uname -a
FreeBSD c720-r314251-vale 12.0-CURRENT FreeBSD 12.0-CURRENT #1 r314251M: Tue 
Apr  2 07:19:39 CEST 2019 
guru@c720-r314251-vale:/usr/obj/usr/src/sys/GENERIC  amd64

Yesterday we wanted to connect a Canon EOS 300D camera to the USB port and it
showed with gphoto2 the same delay problem. I applied the same patch to
r314251 and all is fine. Thanks

matthias

-- 
Matthias Apitz, ✉ g...@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub
AKL: "This U.E. is neo-liberalistic, anti-democratic and militaristic"
AKL: "Diese EU ist neo-liberal, undemokratisch und militaristisch."


signature.asc
Description: PGP signature

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

2019-01-04 Thread Matthias Apitz 
On Fri, 4 Jan 2019 22:09:27 +0100, Hans Petter Selasky wrote:
> On 1/4/19 7:31 PM, Matthias Apitz wrote:
>> El día viernes, enero 04, 2019 a las 07:02:16p. m. +0100, Hans 
>> Petter Selasky escribió:
>> 
>>> On 1/4/19 7:03 PM, Matthias Apitz wrote:
 I've applied the 2nd patch on the already patched sources, it fails.
 Should I use the original sources without your first patch?
>>>
>>> You should revert all prior patches.
>> 
>> Done. Please find attached the messages. I did 'usbconfig list' and this
>> is marked with this string in the messages.
>
> The attached log looks good. I assume the patch still fixes your issue - 
> right?
>
> https://svnweb.freebsd.org/changeset/base/342778
>
> --HPS

Yes, thanks. The pcscd wotks with the token as it should. Thanks for wading 
through.

matthias




-- 
Sent using Dekko from my Ubuntu device
http://www.unixarea.de/+49 176 38902045
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 7:31 PM, Matthias Apitz wrote:

El día viernes, enero 04, 2019 a las 07:02:16p. m. +0100, Hans Petter Selasky 
escribió:


On 1/4/19 7:03 PM, Matthias Apitz wrote:

I've applied the 2nd patch on the already patched sources, it fails.
Should I use the original sources without your first patch?


You should revert all prior patches.


Done. Please find attached the messages. I did 'usbconfig list' and this
is marked with this string in the messages.


The attached log looks good. I assume the patch still fixes your issue - 
right?


https://svnweb.freebsd.org/changeset/base/342778

--HPS

___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Matthias Apitz 
El día viernes, enero 04, 2019 a las 07:02:16p. m. +0100, Hans Petter Selasky 
escribió:

> On 1/4/19 7:03 PM, Matthias Apitz wrote:
> > I've applied the 2nd patch on the already patched sources, it fails.
> > Should I use the original sources without your first patch?
> 
> You should revert all prior patches.

Done. Please find attached the messages. I did 'usbconfig list' and this
is marked with this string in the messages.

Thanks

-- 
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.
Jan  4 19:23:36 c720-r342378 syslogd: kernel boot file is /boot/kernel/kernel
Jan  4 19:23:36 c720-r342378 kernel: ---<>---
Jan  4 19:23:36 c720-r342378 kernel: Copyright (c) 1992-2018 The FreeBSD 
Project.
Jan  4 19:23:36 c720-r342378 kernel: Copyright (c) 1979, 1980, 1983, 1986, 
1988, 1989, 1991, 1992, 1993, 1994
Jan  4 19:23:36 c720-r342378 kernel:The Regents of the University of 
California. All rights reserved.
Jan  4 19:23:36 c720-r342378 kernel: FreeBSD is a registered trademark of The 
FreeBSD Foundation.
Jan  4 19:23:36 c720-r342378 kernel: FreeBSD 13.0-CURRENT GENERIC amd64
Jan  4 19:23:36 c720-r342378 kernel: FreeBSD clang version 7.0.1 
(tags/RELEASE_701/final 349250) (based on LLVM 7.0.1)
Jan  4 19:23:36 c720-r342378 kernel: WARNING: WITNESS option enabled, expect 
reduced performance.
Jan  4 19:23:36 c720-r342378 kernel: VT(vga): resolution 640x480
Jan  4 19:23:36 c720-r342378 kernel: CPU: Intel(R) Celeron(R) 2955U @ 1.40GHz 
(1396.80-MHz K8-class CPU)
Jan  4 19:23:36 c720-r342378 kernel:   Origin="GenuineIntel"  Id=0x40651  
Family=0x6  Model=0x45  Stepping=1
Jan  4 19:23:36 c720-r342378 kernel:   
Features=0xbfebfbff
Jan  4 19:23:36 c720-r342378 kernel:   
Features2=0x4ddaebbf
Jan  4 19:23:36 c720-r342378 kernel:   AMD 
Features=0x2c100800
Jan  4 19:23:36 c720-r342378 kernel:   AMD Features2=0x21
Jan  4 19:23:36 c720-r342378 kernel:   Structured Extended 
Features=0x2603
Jan  4 19:23:36 c720-r342378 kernel:   XSAVE Features=0x1
Jan  4 19:23:36 c720-r342378 kernel:   VT-x: (disabled in BIOS) 
PAT,HLT,MTF,PAUSE,EPT,UG,VPID
Jan  4 19:23:36 c720-r342378 kernel:   TSC: P-state invariant, performance 
statistics
Jan  4 19:23:36 c720-r342378 kernel: real memory  = 4301258752 (4102 MB)
Jan  4 19:23:36 c720-r342378 kernel: avail memory = 1917239296 (1828 MB)
Jan  4 19:23:36 c720-r342378 kernel: Event timer "LAPIC" quality 600
Jan  4 19:23:36 c720-r342378 kernel: ACPI APIC Table: 
Jan  4 19:23:36 c720-r342378 kernel: FreeBSD/SMP: Multiprocessor System 
Detected: 2 CPUs
Jan  4 19:23:36 c720-r342378 kernel: FreeBSD/SMP: 1 package(s) x 2 core(s)
Jan  4 19:23:36 c720-r342378 kernel: random: unblocking device.
Jan  4 19:23:36 c720-r342378 kernel: ioapic0  irqs 0-39 on 
motherboard
Jan  4 19:23:36 c720-r342378 kernel: Launching APs: 1
Jan  4 19:23:36 c720-r342378 kernel: Timecounter "TSC" frequency 1396795928 Hz 
quality 1000
Jan  4 19:23:36 c720-r342378 kernel: Cuse v0.1.35 @ /dev/cuse
Jan  4 19:23:36 c720-r342378 kernel: random: entropy device external interface
Jan  4 19:23:36 c720-r342378 kernel: [ath_hal] loaded
Jan  4 19:23:36 c720-r342378 kernel: kbd1 at kbdmux0
Jan  4 19:23:36 c720-r342378 kernel: module_register_init: MOD_LOAD (vesa, 
0x81124550, 0) error 19
Jan  4 19:23:36 c720-r342378 kernel: random: registering fast source Intel 
Secure Key RNG
Jan  4 19:23:36 c720-r342378 kernel: random: fast provider: "Intel Secure Key 
RNG"
Jan  4 19:23:36 c720-r342378 kernel: 000.52 [4184] netmap_init  
 netmap: loaded module
Jan  4 19:23:36 c720-r342378 kernel: nexus0
Jan  4 19:23:36 c720-r342378 kernel: vtvga0:  on motherboard
Jan  4 19:23:36 c720-r342378 kernel: cryptosoft0:  on 
motherboard
Jan  4 19:23:36 c720-r342378 kernel: acpi0:  on motherboard
Jan  4 19:23:36 c720-r342378 kernel: acpi0: Power Button (fixed)
Jan  4 19:23:36 c720-r342378 kernel: hpet0:  iomem 
0xfed0-0xfed003ff on acpi0
Jan  4 19:23:36 c720-r342378 kernel: Timecounter "HPET" frequency 14318180 Hz 
quality 950
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET" frequency 14318180 Hz 
quality 550
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET1" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET2" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET3" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET4" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET5" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: Event timer "HPET6" frequency 14318180 Hz 
quality 440
Jan  4 19:23:36 c720-r342378 kernel: cpu0:  on acpi0
Jan  4 19:23:36 c720-r342378 kernel: atrtc0:  port 0x70-0x77 
on acpi0
Jan  4 19:23:36 c720-r342378 kernel: atrtc0: regis

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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 7:03 PM, Matthias Apitz wrote:

I've applied the 2nd patch on the already patched sources, it fails.
Should I use the original sources without your first patch?


You should revert all prior patches.

--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Matthias Apitz 
El día viernes, enero 04, 2019 a las 05:09:09p. m. +0100, Hans Petter Selasky 
escribió:

> 
> Can you try this patch aswell and attach new logs?

I've applied the 2nd patch on the already patched sources, it fails.
Should I use the original sources without your first patch?

mattias


-- 
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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 5:05 PM, Hans Petter Selasky wrote:

On 1/4/19 4:27 PM, Matthias Apitz wrote:
El día viernes, enero 04, 2019 a las 12:45:47p. m. +0100, Hans Petter 
Selasky escribió:



On 1/4/19 11:46 AM, Matthias Apitz wrote:
Jan  4 11:26:39 c720-r342378 kernel: uhub_read_port_status: port 13, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0xe070, wPortChange=0x161e, err=USB_ERR_TIMEOUT
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 2, 
wPortStatus=0x0500, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION


Hi,

The problem appears to be that one of the USB HUBs port status request
don't respond: USB_ERR_TIMEOUT, which in turn blocks the enumeration 
thread.


Can you try the attached kernel patch and send new debug log?


Hi,

I applied the patch and the new debug output is attached.

And it works now as it should, without any devd(8) hook. I just start
pcsdd as a service via rc.conf and can attach or withdraw the security
token. When the token is not attached GnuPG asks me to insert it and
when it is inserted I'm asked for the PIN. All as it should be

A big THANKS!

Should I file a PR to get your patch included upstream?



No PR needed, but I might need you to test one more patch.



Can you try this patch aswell and attach new logs?

Thank you!

--HPS

Index: sys/dev/usb/usb_hub.c
===
--- sys/dev/usb/usb_hub.c	(revision 342455)
+++ sys/dev/usb/usb_hub.c	(working copy)
@@ -129,6 +129,8 @@
 	int sc_disable_enumeration;
 	int sc_disable_port_power;
 #endif
+	uint8_t sc_usb_port_errors;	/* error counter */
+#define	UHUB_USB_PORT_ERRORS_MAX 4
 	uint8_t	sc_flags;
 #define	UHUB_FLAG_DID_EXPLORE 0x01
 };
@@ -587,14 +589,26 @@
 	struct usb_port_status ps;
 	usb_error_t err;
 
+	if (sc->sc_usb_port_errors >= UHUB_USB_PORT_ERRORS_MAX) {
+		DPRINTFN(4, "port %d, HUB looks dead, too many errors\n", portno);
+		sc->sc_st.port_status = 0;
+		sc->sc_st.port_change = 0;
+		return (USB_ERR_TIMEOUT);
+	}
+
 	err = usbd_req_get_port_status(
 	sc->sc_udev, NULL, &ps, portno);
 
-	/* update status regardless of error */
+	if (err == 0) {
+		sc->sc_st.port_status = UGETW(ps.wPortStatus);
+		sc->sc_st.port_change = UGETW(ps.wPortChange);
+		sc->sc_usb_port_errors = 0;
+	} else {
+		sc->sc_st.port_status = 0;
+		sc->sc_st.port_change = 0;
+		sc->sc_usb_port_errors++;
+	}
 
-	sc->sc_st.port_status = UGETW(ps.wPortStatus);
-	sc->sc_st.port_change = UGETW(ps.wPortChange);
-
 	/* debugging print */
 
 	DPRINTFN(4, "port %d, wPortStatus=0x%04x, "
Index: sys/dev/usb/usb_request.c
===
--- sys/dev/usb/usb_request.c	(revision 342455)
+++ sys/dev/usb/usb_request.c	(working copy)
@@ -1601,8 +1601,9 @@
 	USETW(req.wValue, 0);
 	req.wIndex[0] = port;
 	req.wIndex[1] = 0;
-	USETW(req.wLength, sizeof *ps);
-	return (usbd_do_request(udev, mtx, &req, ps));
+	USETW(req.wLength, sizeof(*ps));
+
+	return (usbd_do_request_flags(udev, mtx, &req, ps, 0, NULL, 1000));
 }
 
 /**
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 4:27 PM, Matthias Apitz wrote:

El día viernes, enero 04, 2019 a las 12:45:47p. m. +0100, Hans Petter Selasky 
escribió:


On 1/4/19 11:46 AM, Matthias Apitz wrote:

Jan  4 11:26:39 c720-r342378 kernel: uhub_read_port_status: port 13, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0xe070, wPortChange=0x161e, err=USB_ERR_TIMEOUT
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 2, 
wPortStatus=0x0500, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION


Hi,

The problem appears to be that one of the USB HUBs port status request
don't respond: USB_ERR_TIMEOUT, which in turn blocks the enumeration thread.

Can you try the attached kernel patch and send new debug log?


Hi,

I applied the patch and the new debug output is attached.

And it works now as it should, without any devd(8) hook. I just start
pcsdd as a service via rc.conf and can attach or withdraw the security
token. When the token is not attached GnuPG asks me to insert it and
when it is inserted I'm asked for the PIN. All as it should be

A big THANKS!

Should I file a PR to get your patch included upstream?



No PR needed, but I might need you to test one more patch.

--HPS

___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Matthias Apitz 
El día viernes, enero 04, 2019 a las 12:45:47p. m. +0100, Hans Petter Selasky 
escribió:

> On 1/4/19 11:46 AM, Matthias Apitz wrote:
> > Jan  4 11:26:39 c720-r342378 kernel: uhub_read_port_status: port 13, 
> > wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
> > Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 1, 
> > wPortStatus=0xe070, wPortChange=0x161e, err=USB_ERR_TIMEOUT
> > Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 2, 
> > wPortStatus=0x0500, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
> 
> Hi,
> 
> The problem appears to be that one of the USB HUBs port status request 
> don't respond: USB_ERR_TIMEOUT, which in turn blocks the enumeration thread.
> 
> Can you try the attached kernel patch and send new debug log?

Hi,

I applied the patch and the new debug output is attached.

And it works now as it should, without any devd(8) hook. I just start
pcsdd as a service via rc.conf and can attach or withdraw the security
token. When the token is not attached GnuPG asks me to insert it and
when it is inserted I'm asked for the PIN. All as it should be

A big THANKS!

Should I file a PR to get your patch included upstream?

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.
Jan  4 16:19:15 c720-r342378 ipmon[738]: 16:19:15.433507 wlan0 @0:13 p 
192.168.2.106,40444 -> 192.168.2.1,53 PR udp len 20 60 K-S OUT
Jan  4 16:19:15 c720-r342378 ipmon[738]: 16:19:15.437243 wlan0 @0:13 p 
192.168.2.1,53 -> 192.168.2.106,40444 PR udp len 20 76 K-S IN
Jan  4 16:19:18 c720-r342378 kernel: uhub_read_port_status: port 1, Trying 
again, err=USB_ERR_TIMEOUT
Jan  4 16:19:19 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0x, wPortChange=0x, err=USB_ERR_TIMEOUT
Jan  4 16:19:19 c720-r342378 kernel: uhub_read_port_status: port 2, 
wPortStatus=0x0500, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: usb_needs_explore: 
Jan  4 16:19:21 c720-r342378 kernel: usb_bus_powerd: bus=0xfe784428
Jan  4 16:19:21 c720-r342378 kernel: usb_bus_powerd: Recomputing power masks
Jan  4 16:19:21 c720-r342378 kernel: uhub_explore: udev=0xf8000351c000 
addr=1
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 2, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 3, 
wPortStatus=0x0503, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 4, 
wPortStatus=0x0103, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 5, 
wPortStatus=0x0103, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 6, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 7, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 8, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 9, 
wPortStatus=0x0780, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 10, 
wPortStatus=0x07a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 11, 
wPortStatus=0x07a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 12, 
wPortStatus=0x07a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 13, 
wPortStatus=0x07a0, wPortChange=0x0020, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: usb_needs_explore: 
Jan  4 16:19:21 c720-r342378 kernel: usb_bus_powerd: bus=0xfe001ac4fcd8
Jan  4 16:19:21 c720-r342378 kernel: usb_bus_powerd: Recomputing power masks
Jan  4 16:19:21 c720-r342378 kernel: uhub_explore: udev=0xf80003805000 
addr=1
Jan  4 16:19:21 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0x0503, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 16:19:21 c720-r342378 kernel: uhub_explore: udev=0xf800161e9000 
addr=2
Jan  4 16:19:21 c720-r342378 kernel: usbd_transfer_power_ref: Adding type 0 to 
power state
Jan  4 16:19:21 c720-r342378 kernel: usbd_transfer_power_ref: needs power
Jan  4 16:19:22 c720-r342378 kernel: uhub_read_port_status: port 1, Trying 
again,

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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 11:46 AM, Matthias Apitz wrote:

Jan  4 11:26:39 c720-r342378 kernel: uhub_read_port_status: port 13, 
wPortStatus=0x07a0, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 1, 
wPortStatus=0xe070, wPortChange=0x161e, err=USB_ERR_TIMEOUT
Jan  4 11:26:41 c720-r342378 kernel: uhub_read_port_status: port 2, 
wPortStatus=0x0500, wPortChange=0x, err=USB_ERR_NORMAL_COMPLETION


Hi,

The problem appears to be that one of the USB HUBs port status request 
don't respond: USB_ERR_TIMEOUT, which in turn blocks the enumeration thread.


Can you try the attached kernel patch and send new debug log?

--HPS
Index: sys/dev/usb/usb_hub.c
===
--- sys/dev/usb/usb_hub.c	(revision 342455)
+++ sys/dev/usb/usb_hub.c	(working copy)
@@ -590,11 +590,23 @@
 	err = usbd_req_get_port_status(
 	sc->sc_udev, NULL, &ps, portno);
 
-	/* update status regardless of error */
+	if (err != 0) {
+		DPRINTFN(4, "port %d, Trying again, err=%s\n",
+		   portno, usbd_errstr(err));
 
-	sc->sc_st.port_status = UGETW(ps.wPortStatus);
-	sc->sc_st.port_change = UGETW(ps.wPortChange);
+		/* try a second time before giving up */
+		err = usbd_req_get_port_status(
+		sc->sc_udev, NULL, &ps, portno);
+	}
 
+	if (err == 0) {
+		sc->sc_st.port_status = UGETW(ps.wPortStatus);
+		sc->sc_st.port_change = UGETW(ps.wPortChange);
+	} else {
+		sc->sc_st.port_status = 0;
+		sc->sc_st.port_change = 0;
+	}
+
 	/* debugging print */
 
 	DPRINTFN(4, "port %d, wPortStatus=0x%04x, "
Index: sys/dev/usb/usb_request.c
===
--- sys/dev/usb/usb_request.c	(revision 342455)
+++ sys/dev/usb/usb_request.c	(working copy)
@@ -1601,8 +1601,9 @@
 	USETW(req.wValue, 0);
 	req.wIndex[0] = port;
 	req.wIndex[1] = 0;
-	USETW(req.wLength, sizeof *ps);
-	return (usbd_do_request(udev, mtx, &req, ps));
+	USETW(req.wLength, sizeof(*ps));
+
+	return (usbd_do_request_flags(udev, mtx, &req, ps, 0, NULL, 1000));
 }
 
 /**
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Hans Petter Selasky 

On 1/4/19 9:02 AM, Matthias Apitz wrote:

We definitely should resolve this before anything else.

The output of the 'usbconfig list' was:

# 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)

Any comments on this ugen1.X?


Hi,

Can you collect USB HUB debug messages in dmesg?

sysctl hw.usb.uhub.debug=16

Then reproduce then hang and send relevant output from "/var/log/messages".

It seems to me like something is constantly keeping the USB enumeration 
thread busy. This can for example be:


1) fake USB plug/unplug events
2) pcscd going into a loop

--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-04 Thread Matthias Apitz 
El día jueves, enero 03, 2019 a las 01:36:08p. m. +0100, Ludovic Rousseau 
escribió:

> I hope this email will go to freebsd-usb@ since I am not a member of this 
> list.
> 
> Le jeu. 3 janv. 2019 à 13:19, Hans Petter Selasky  a écrit :
> >
> > On 1/3/19 12:35 PM, Matthias Apitz wrote:
> > > but is doing so 3000++ times:
> > >
> > > $ dmesg | grep 'PID 544' | wc -l
> > >  3441
> > >
> > > This proc is started by devd(8)  with that devd(8) hook:
> > >
> >
> > Hi,
> >
> > Basically pcscd is congesting the enumeration SX lock, preventing
> > usbconfig from running because it tries to open the same USB device over
> > and over again. I'm not sure why, but it can have something to do with
> > how you start pcscd.
> >
> > Can you try to use the example rules given by the pcscd packet message?
> >
> > attach 100 {
> >  device-name "ugen[0-9]+";
> >  action "/usr/local/sbin/pcscd -H";
> > };
> >
> > detach 100 {
> >  device-name "ugen[0-9]+";
> >  action "/usr/local/sbin/pcscd -H";
> > };

Btw: for the above devd(8) hooks one must also start
/usr/local/sbin/pcscd as a service via /usr/local/etc/rc.d/pcscd

> > Maybe there is a bug in pcsd that it tries to open the same USB device
> > over and over again if there is an libusb error? Maybe it should sleep a
> > bit before trying to re-enumerate devices?
> >
> > I'm CC'ing Ludovic Rousseau, in case he has any comments.
> 
> You can enable pcscd hotplug debug by editing DEBUG_HOTPLUG at
> https://salsa.debian.org/rousseau/PCSC/blob/master/src/hotplug_libusb.c#L69
> 
> A pcscd trace would be helpful. See https://pcsclite.apdu.fr/#support

Hello Ludovic and Hans,

First of all, thanks for your helping hands!

I will later come back to the debugging of pcscd itself. But before that
we should solve the problem outside of pcscd.

I did today morning:

1. power-off
2. insert the uTrust token
3. power-on boot *without* any devd(8) or service start of pcscd

here are the last boot messages in /var/log/messages:

Jan  4 07:49:43 c720-r342378 kernel: uhub0: 13 ports with 13 removable, self 
powered
Jan  4 07:49:43 c720-r342378 kernel: uhub1: 2 ports with 2 removable, self 
powered
Jan  4 07:49:43 c720-r342378 kernel: ugen0.2:  at 
usbus0
Jan  4 07:49:43 c720-r342378 kernel: ugen1.2:  at 
usbus1
Jan  4 07:49:43 c720-r342378 kernel: uhub2 on uhub1
Jan  4 07:49:43 c720-r342378 kernel: uhub2:  on usbus1
Jan  4 07:49:43 c720-r342378 kernel: ugen0.3:  at 
usbus0
Jan  4 07:49:43 c720-r342378 kernel: uhub2: 8 ports with 8 removable, self 
powered
Jan  4 07:49:43 c720-r342378 kernel: ugen0.4:  at usbus0
Jan  4 07:49:43 c720-r342378 kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0
Jan  4 07:49:43 c720-r342378 kernel: ada0:  ACS-2 ATA SATA 
3.x device
Jan  4 07:49:43 c720-r342378 kernel: ada0: Serial Number C196530955
Jan  4 07:49:43 c720-r342378 kernel: ada0: 600.000MB/s transfers (SATA 3.x, 
UDMA6, PIO 1024bytes)
Jan  4 07:49:43 c720-r342378 kernel: ada0: Command Queueing enabled
Jan  4 07:49:43 c720-r342378 kernel: ada0: 244198MB (500118192 512 byte sectors)
Jan  4 07:49:43 c720-r342378 kernel: WARNING: WITNESS option enabled, expect 
reduced performance.
Jan  4 07:49:43 c720-r342378 kernel: Trying to mount root from ufs:/dev/ada0p2 
[rw,noatime]...
Jan  4 07:49:43 c720-r342378 kernel: wlan0: Ethernet address: 90:48:9a:92:9e:43
Jan  4 07:49:43 c720-r342378 kernel: lo0: link state changed to UP
Jan  4 07:49:43 c720-r342378 kernel: .
Jan  4 07:49:48 c720-r342378 dbus[882]: [system] Activating service 
name='org.freedesktop.ColorManager' (using servicehelper)
Jan  4 07:49:48 c720-r342378 dbus[882]: [system] Successfully activated service 
'org.freedesktop.ColorManager'

4. Login as root and then I started as root 'tcpdump -o usbconfig.tr -d 
usbconfig list'
   resulting lines in messages:

Jan  4 07:53:04 c720-r342378 login[989]: ROOT LOGIN (root) ON ttyv1
Jan  4 07:53:51 c720-r342378 kernel: USB opened by PID 1005 usbconfig
Jan  4 07:53:51 c720-r342378 syslogd: last message repeated 1 times
Jan  4 07:54:38 c720-r342378 kernel: USB opened by PID 1019 usbconfig
Jan  4 07:55:01 c720-r342378 syslogd: last message repeated 3 times
Jan  4 07:56:50 c720-r342378 syslogd: last message repeated 4 times

And the trace file usbconfig.tr is attached. Please see the timestamps
in each line. The printed time is when the syscall ended(!) and a close
look shows:

...
176.947374653 close(3)   = 0 (0x0)
176.947633175 openat(AT_FDCWD,"/dev/ugen0.1",O_RDWR,00) = 3 (0x3)
176.947831569 openat(AT_FDCWD,"/dev/ugen0.1",O_RDWR,00) = 4 (0x4)
176.947933598 ioctl(4,USB_GET_PLUGTIME,0x7fffe9ac) = 0 (0x0)
...

176.950045979 close(3)   = 0 (0x0)
201.816756320 openat(AT_FDCWD,"/dev/ugen1.1",O_RDWR,00) = 3 (0x3)
216.766758812 openat(AT_FDCWD,"/dev/ugen1.1",O_RDWR,00) = 4 (0x4)
221.728691723 ioctl(4,USB_GET_PLUGTIME,0x7fffe9ac) = 0 (0x0)

i.e. all openat(2) and ioctl(2) calls for /dev/ugen0.X devices are
normal, while the calls f

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

2019-01-03 Thread Hans Petter Selasky 

On 1/3/19 1:36 PM, Ludovic Rousseau wrote:

I hope this email will go to freebsd-usb@ since I am not a member of this list.

Le jeu. 3 janv. 2019 à 13:19, Hans Petter Selasky  a écrit :


On 1/3/19 12:35 PM, Matthias Apitz wrote:

but is doing so 3000++ times:

$ dmesg | grep 'PID 544' | wc -l
  3441

This proc is started by devd(8)  with that devd(8) hook:



Hi,

Basically pcscd is congesting the enumeration SX lock, preventing
usbconfig from running because it tries to open the same USB device over
and over again. I'm not sure why, but it can have something to do with
how you start pcscd.

Can you try to use the example rules given by the pcscd packet message?

attach 100 {
  device-name "ugen[0-9]+";
  action "/usr/local/sbin/pcscd -H";
};

detach 100 {
  device-name "ugen[0-9]+";
  action "/usr/local/sbin/pcscd -H";
};

Maybe there is a bug in pcsd that it tries to open the same USB device
over and over again if there is an libusb error? Maybe it should sleep a
bit before trying to re-enumerate devices?

I'm CC'ing Ludovic Rousseau, in case he has any comments.




Hi Matthias,

Can you try this:


You can enable pcscd hotplug debug by editing DEBUG_HOTPLUG at
https://salsa.debian.org/rousseau/PCSC/blob/master/src/hotplug_libusb.c#L69

A pcscd trace would be helpful. See https://pcsclite.apdu.fr/#support



--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-03 Thread Ludovic Rousseau 
I hope this email will go to freebsd-usb@ since I am not a member of this list.

Le jeu. 3 janv. 2019 à 13:19, Hans Petter Selasky  a écrit :
>
> On 1/3/19 12:35 PM, Matthias Apitz wrote:
> > but is doing so 3000++ times:
> >
> > $ dmesg | grep 'PID 544' | wc -l
> >  3441
> >
> > This proc is started by devd(8)  with that devd(8) hook:
> >
>
> Hi,
>
> Basically pcscd is congesting the enumeration SX lock, preventing
> usbconfig from running because it tries to open the same USB device over
> and over again. I'm not sure why, but it can have something to do with
> how you start pcscd.
>
> Can you try to use the example rules given by the pcscd packet message?
>
> attach 100 {
>  device-name "ugen[0-9]+";
>  action "/usr/local/sbin/pcscd -H";
> };
>
> detach 100 {
>  device-name "ugen[0-9]+";
>  action "/usr/local/sbin/pcscd -H";
> };
>
> Maybe there is a bug in pcsd that it tries to open the same USB device
> over and over again if there is an libusb error? Maybe it should sleep a
> bit before trying to re-enumerate devices?
>
> I'm CC'ing Ludovic Rousseau, in case he has any comments.

You can enable pcscd hotplug debug by editing DEBUG_HOTPLUG at
https://salsa.debian.org/rousseau/PCSC/blob/master/src/hotplug_libusb.c#L69

A pcscd trace would be helpful. See https://pcsclite.apdu.fr/#support

Bye

-- 
 Dr. Ludovic Rousseau
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-03 Thread Hans Petter Selasky 

On 1/3/19 12:35 PM, Matthias Apitz wrote:

but is doing so 3000++ times:

$ dmesg | grep 'PID 544' | wc -l
 3441

This proc is started by devd(8)  with that devd(8) hook:



Hi,

Basically pcscd is congesting the enumeration SX lock, preventing 
usbconfig from running because it tries to open the same USB device over 
and over again. I'm not sure why, but it can have something to do with 
how you start pcscd.


Can you try to use the example rules given by the pcscd packet message?

attach 100 {
device-name "ugen[0-9]+";
action "/usr/local/sbin/pcscd -H";
};

detach 100 {
device-name "ugen[0-9]+";
action "/usr/local/sbin/pcscd -H";
};

Maybe there is a bug in pcsd that it tries to open the same USB device 
over and over again if there is an libusb error? Maybe it should sleep a 
bit before trying to re-enumerate devices?


I'm CC'ing Ludovic Rousseau, in case he has any comments.

--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-03 Thread Matthias Apitz 
El día jueves, enero 03, 2019 a las 11:03:26a. m. +0100, Hans Petter Selasky 
escribió:

> On 1/3/19 10:48 AM, Matthias Apitz wrote:
> > Is there a way log log any init call to libusb.so to see which process
> > is doing something with libusb.so after devd(8) started pcscd?
> 
> Hi,
> 
> You can add a print in the kernel sys/dev/usb/usb_generic.c in the function:
> 
> static int
> ugen_open(struct usb_fifo *f, int fflags)
> 
> 
> printf("USB opened by PID %d %s\n", curthread->td_proc->p_pid, 
> curthread->td_proc->p_comm);

Hi,

I've added the code and rebooted the new kernel. The only PID requesting
the ugen_open() is PID 544 pcscd, which is 

$ dmesg | grep PID
...
USB opened by PID 544 pcscd
USB opened by PID 544 pcscd
USB opened by PID 544 pcscd
USB opened by PID 544 pcscd
USB opened by PID 544 pcscd
USB opened by PID 544 pcscd


$ ps ax | grep 544
 544 v0- S 0:00,51 /usr/local/sbin/pcscd --debug --foreground

but is doing so 3000++ times:

$ dmesg | grep 'PID 544' | wc -l
3441

This proc is started by devd(8)  with that devd(8) hook:


notify 1000 {
match "system" "USB";
match "subsystem" "INTERFACE";
match "type" "ATTACH";
# uTrust
match "vendor"  "0x04e6";
match "product" "0x5816";
action "logger CCID uTrust, type: $type, system: $system, subsystem: 
$subsystem"; 
action "logger /usr/local/sbin/pcscd --debug --foreground ";
action "nohup /usr/local/sbin/pcscd --debug --foreground &";
};
#
notify 1000 {
match "system" "USB";
match "subsystem" "INTERFACE";
match "type" "ATTACH";
# HID Omnikey
match "vendor"  "0x076b";
match "product" "0x6632";
action "logger CCID HID Omnikey, type: $type, system: $system, 
subsystem: $subsystem"; 
action "logger /usr/local/sbin/pcscd --debug --foreground ";
action "nohup /usr/local/sbin/pcscd --debug --foreground & ";
};
#
notify 1000 {
match "system" "USB";
match "subsystem" "INTERFACE";
match "type" "DETACH";
# uTrust
match "vendor"  "0x04e6";
match "product" "0x5816";
action "logger CCID uTrust, type: $type, system: $system, subsystem: 
$subsystem"; 
action "logger killall  pcscd";
action "killall  pcscd";
};
#
notify 1000 {
match "system" "USB";
match "subsystem" "INTERFACE";
match "type" "DETACH";
# HID Omnikey
match "vendor"  "0x076b";
match "product" "0x6632";
action "logger CCID HID Omnikey, type: $type, system: $system, 
subsystem: $subsystem"; 
action "logger killall  pcscd";
action "killall  pcscd";
};

-- 
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

2019-01-03 Thread Hans Petter Selasky 

On 1/3/19 10:48 AM, Matthias Apitz wrote:

Is there a way log log any init call to libusb.so to see which process
is doing something with libusb.so after devd(8) started pcscd?


Hi,

You can add a print in the kernel sys/dev/usb/usb_generic.c in the function:

static int
ugen_open(struct usb_fifo *f, int fflags)


printf("USB opened by PID %d %s\n", curthread->td_proc->p_pid, 
curthread->td_proc->p_comm);




Index: sys/dev/usb/usb_generic.c
===
--- sys/dev/usb/usb_generic.c   (revision 342455)
+++ sys/dev/usb/usb_generic.c   (working copy)
@@ -185,6 +185,8 @@
 
 	DPRINTFN(6, "flag=0x%x\n", fflags);
 
+	printf("USB opened by PID %d %s\n", curthread->td_proc->p_pid, curthread->td_proc->p_comm);

+
mtx_lock(f->priv_mtx);
switch (usbd_get_speed(f->udev)) {
case USB_SPEED_LOW:



--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-03 Thread Matthias Apitz 
El día jueves, enero 03, 2019 a las 09:31:53a. m. +0100, Hans Petter Selasky 
escribió:

> On 1/3/19 7:04 AM, Matthias Apitz wrote:
> > I think, we should isolate the problem from PCSC and focus (first) on the
> > question why are calls to usbconfig(8) are not answered anymore
> > *without*  any kind of PCSC software being involved as I wrote in the
> > originating email of this thread. Here it is again in case in got lost
> > while talking about PCSC:
> 
> Hi,
> 
> Usually this happens if a user-space component is not closing its device 
> handle while enumeration happens. Can you run pcsd in the foreground 
> with debugging enabled and show what it prints while you plug unplug the 
> device.
> 
> Also try setting the hw.usb.uhub.debug=16 sysctl and collect messages in 
> dmesg.

Hi,

I wasn't lazy and did several tests as root:

1. booting to single user mode with the token attached:

   running usbconfig(8) works fine and fast; tested multiple times the
   cmd, no delays;

2. booting to multiuser, login as root, no KDE started, just first login
   as root in multiuser; devd(8) hook was moved away before booting;

   running 'truss -o usbconfig.tr -d usbconfig list' gives the attached
   output; long delays on open of the ugen0.X files:

3. re-boot again to multiuser, login as root, no KDE starting as root;
   again without the devd(8) hook for the card:

   running as root:

   /usr/local/sbin/pcscd --debug --foreground > pcscd.stdout

   gives:

    pcscdaemon.c:347:main() pcscd set to foreground with debug send to 
stdout
   0554 configfile.l:361:DBGetReaderList() Parsing conf file: 
/usr/local/etc/reader.conf.d
   0062 pcscdaemon.c:662:main() pcsc-lite 1.8.23 daemon ready.

   no reaction on plug-in or card detach; then I killed it with Ctrl-C

   77360913 pcscdaemon.c:193:signal_thread() Received signal: 2
   0063 pcscdaemon.c:226:signal_thread() Preparing for suicide
   02189136 pcscdaemon.c:193:signal_thread() Received signal: 2
   00639842 pcscdaemon.c:193:signal_thread() Received signal: 2
   0055 pcscdaemon.c:247:signal_thread() Forced suicide
   0020 pcscdaemon.c:785:at_exit() cleaning /var/run/pcscd

4. with devd(8) hook active, booted into multiuser the pcscd started by
   devd(8) works fine until detaching the card (which let devd(8) kill
   the running pcscd; a new started pcscd will not work anymore;

This means: something during boot damages the USB stack; this must be
something after devd(8) bring up pcscd (because this is still fine
working).

Is there a way log log any init call to libusb.so to see which process
is doing something with libusb.so after devd(8) started pcscd?

An option to test is deleting the devd(8) hooks for DETACH and
let pcscd just continue and see if ATTACH of the card works ...

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

2019-01-03 Thread Hans Petter Selasky 

On 1/3/19 7:04 AM, Matthias Apitz wrote:

I think, we should isolate the problem from PCSC and focus (first) on the
question why are calls to usbconfig(8) are not answered anymore
*without*  any kind of PCSC software being involved as I wrote in the
originating email of this thread. Here it is again in case in got lost
while talking about PCSC:


Hi,

Usually this happens if a user-space component is not closing its device 
handle while enumeration happens. Can you run pcsd in the foreground 
with debugging enabled and show what it prints while you plug unplug the 
device.


Also try setting the hw.usb.uhub.debug=16 sysctl and collect messages in 
dmesg.


--HPS
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread Matthias Apitz 
El día miércoles, enero 02, 2019 a las 05:04:42p. m. +0100, Hans Petter Selasky 
escribió:

> Let's move this thread freebsd-usb only.
> 
> Have a look here:
> 
> https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=231076

I read carefully through the PR 231076 (and deleted freebsd-current from
the mail thread). The PR does not match my problem.

I think, we should isolate the problem from PCSC and focus (first) on the
question why are calls to usbconfig(8) are not answered anymore
*without* any kind of PCSC software being involved as I wrote in the
originating email of this thread. Here it is again in case in got lost
while talking about PCSC:

If it would help, I could file a new separate PR with the dates below.



I updated my amd64 laptop Acer C720 from r314251 to r342378. ...

 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.

...

Ther first 3 commands usbconfig(8) are answered immediately, then it
takes minutes to get any response. Why?

# 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.


signature.asc
Description: PGP signature

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

2019-01-02 Thread Matthias Apitz 
El día miércoles, enero 02, 2019 a las 06:15:18p. m. +0100, Hans Petter Selasky 
escribió:

> On 1/2/19 6:14 PM, Matthias Apitz wrote:
> > On Wed, 2 Jan 2019 16:57:44 +0100, 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.
> >>
> > 
> > They are made and used for years by me.
> 
> Hi,
> 
> You possibly need to kill pcsd with -KILL signal. Can you try to remove 
> that devd(8) rule and see what happens and start pcsd as a service. It 
> should no longer be needed.

I did so (before reading your mail). When I start pcsd via
/usr/local/etc/rc.d/pcsd (provided by the port), the boot hangs when
pcsd is started.

I will read later (maybe tomorrow) the PR you pointed me to. Thanks

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

2019-01-02 Thread Hans Petter Selasky 

On 1/2/19 6:14 PM, Matthias Apitz wrote:

On Wed, 2 Jan 2019 16:57:44 +0100, 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.



They are made and used for years by me.


Hi,

You possibly need to kill pcsd with -KILL signal. Can you try to remove 
that devd(8) rule and see what happens and start pcsd as a service. It 
should no longer be needed.


--HPS

___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread Matthias Apitz 
On Wed, 2 Jan 2019 16:57:44 +0100, 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.
>

They are made and used for years by me.


-- 
Sent using Dekko from my Ubuntu device
http://www.unixarea.de/+49 176 38902045
___
freebsd-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread Hans Petter Selasky 

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-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread Hans Petter Selasky 

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-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread 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:  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-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread Hans Petter Selasky 

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-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"

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

2019-01-02 Thread 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 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

2019-01-02 Thread Hans Petter Selasky 

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-usb@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-usb
To unsubscribe, send any mail to "freebsd-usb-unsubscr...@freebsd.org"