NetBSD Problem Report #57518

From www@netbsd.org  Mon Jul 10 16:43:07 2023
Return-Path: <www@netbsd.org>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 0594A1A923D
	for <gnats-bugs@gnats.NetBSD.org>; Mon, 10 Jul 2023 16:43:07 +0000 (UTC)
Message-Id: <20230710164305.821D01A923E@mollari.NetBSD.org>
Date: Mon, 10 Jul 2023 16:43:05 +0000 (UTC)
From: a.e.hecht@t-online.de
Reply-To: a.e.hecht@t-online.de
To: gnats-bugs@NetBSD.org
Subject: usb keyboard causes host controller to miss microframe
X-Send-Pr-Version: www-1.0

>Number:         57518
>Category:       kern
>Synopsis:       usb keyboard causes host controller to miss microframe
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    skrll
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Mon Jul 10 16:45:00 +0000 2023
>Closed-Date:    Wed Aug 02 10:45:20 +0000 2023
>Last-Modified:  Wed Aug 02 10:45:20 +0000 2023
>Originator:     Andreas Hecht
>Release:        NetBSD 10.99.5
>Organization:
N/A
>Environment:
NetBSD pc.domain.home 10.99.5 NetBSD 10.99.5 (MYKERNEL) #15: Sat Jul 8 12:50:37 CEST 2023 andreas@pc.domain.home:/home/andreas/git/netbsd/src/sys/arch/amd64/compile/obj/MYKERNEL amd64
>Description:
My USB keyboard (Leopold FC750R PD) causes the USB 2.0 host controller to miss
a required complete-split transaction. 

These are the system messages (-> dmesg) which occur when the keyboard gets
plugged in:

[    35.554780] uhidev1 at uhub2 port 6 configuration 1 interface 0
[    35.554780] uhidev1: HID Keyboard (0x4b4) HID Keyboard (0x510), rev 2.00/2.01, addr 4, iclass 3/1
[    35.554780] ukbd0 at uhidev1
[    35.965206] wskbd1 at ukbd0 mux 1
[    35.965206] wskbd1: connecting to wsdisplay0
[    35.965206] uhidev2 at uhub2 port 6 configuration 1 interface 1
[    35.965206] uhidev2: HID Keyboard (0x4b4) HID Keyboard (0x510), rev 2.00/2.01, addr 4, iclass 3/1
[    35.965206] uhidev2: 8 report ids
[    35.975217] uhid1 at uhidev2 reportid 1: input=2, output=0, feature=0
[    35.975217] ukbd1 at uhidev2 reportid 8
[    36.385643] wskbd2 at ukbd1 mux 1
[    36.385643] wskbd2: connecting to wsdisplay0

This is the error message (-> dmesg) which occurs when a key is pressed:

[    44.093653] ehci1: missed microframe, TT reset not implemented, hub might be inoperational

Here is the usbhist debug output (-> vmstat -u usbhist) of a single 'key press
and release event' of the affected keyboard generated with a kernel compiled
with USB_DEBUG and EHCI_DEBUG and hw.ehci.debug set to '1':

50000 entries, next is 113
1685992014.561408 ehci_intr#1@0: called!
1685992014.561409 ehci_intr1#1@0: called!
1685992014.561410 ehci_intr1#1@0: sc=0xffff82d6f556d000 intrs=0xb(0xc00b) eintrs=0x3
1685992014.561411 ehci_intr1#1@0: INT=1  ERRINT=1
1685992014.561412 ehci_softintr#1@0: called!
1685992014.561413 ehci_check_qh_intr#1@0: called!
1685992014.561414 ehci_dump_sqtds#1@0: called!
1685992014.561414 ehci_dump_sqtd#1@0: called!
1685992014.561415 ehci_dump_qtd#1@0: called!
1685992014.561415 ehci_check_qh_intr#2@0: called!
1685992014.561416 ehci_dump_sqtds#2@0: called!
1685992014.561416 ehci_dump_sqtd#2@0: called!
1685992014.561416 ehci_dump_qtd#2@0: called!
1685992014.561416 ehci_check_qh_intr#3@0: called!
1685992014.561416 ehci_dump_sqtds#3@0: called!
1685992014.561417 ehci_dump_sqtd#3@0: called!
1685992014.561417 ehci_dump_qtd#3@0: called!
1685992014.561417 ehci_check_qh_intr#4@0: called!
1685992014.561417 ehci_idone#1@0: called!
1685992014.561418 ehci_idone#1@0: ex=0xffff82d6f57b1328
1685992014.561418 ehci_idone#1@0: xfer=0xffff82d6f57b1328, pipe=0xffff82d724667e00 ready
1685992014.561419 ehci_dump_sqtds#4@0: called!
1685992014.561419 ehci_dump_sqtd#4@0: called!
1685992014.561419 ehci_dump_qtd#4@0: called!
1685992014.561419 ehci_idone#1@0: toggle update status=0x00088d4e nstatus=0x00088d4e
1685992014.561420 ehci_idone#1@0: len=8 actlen=0 status=0x00088d4e
1685992014.561420 ehci_idone#1@0: halted addr=4 endpt=0x81
1685992014.561420 ehci_idone#1@0: cerr=3 pid=1
1685992014.561420 ehci_idone#1@0: active =0 halted=1 buferr=0 babble=0
1685992014.561421 ehci_idone#1@0: xacterr=1 missed=1 split =1 ping  =0
1685992014.561421 ehci_dump_sqh#1@0: called!
1685992014.561421 ehci_dump_sqh#1@0:     link 0x00000001 (T = 1):
1685992014.561421 ehci_dump_sqh#1@0:         ITD  = 1  QH   = 0  SITD = 0  FSTN = 0
1685992014.561422 ehci_dump_sqh#1@0:     link 0xcad98f80 (T = 0):
1685992014.561422 ehci_dump_qtd#5@0: called!
1685992014.561422 ehci_dump_sqtds#5@0: called!
1685992014.561422 ehci_dump_sqtd#5@0: called!
1685992014.561422 ehci_dump_qtd#6@0: called!
1685992014.561448 ehci_idone#1@0: ex=0xffff82d6f57b1328 done
1685992014.561449 ehci_device_intr_done#1@0: called!
1685992014.561449 ehci_device_intr_done#1@0: xfer=0xffff82d6f57b1328, actlen=0
1685992014.561452 ehci_device_intr_start#1@0: called!
1685992014.561453 ehci_device_intr_start#1@0: xfer=0xffff82d6f57b1328 len=8 flags=4
1685992014.561453 ehci_reset_sqtd_chain#1@0: called!
1685992014.561454 ehci_reset_sqtd_chain#1@0: xfer=0xffff82d6f57b1328 len 8 isread 1 toggle 0
1685992014.561454 ehci_reset_sqtd_chain#1@0:     VA 0xffffb9023a92ef80
1685992014.561454 ehci_reset_sqtd_chain#1@0: sqtd[1]=0xffffb90238f76f80 prev 0
1685992014.561454 ehci_reset_sqtd_chain#1@0:     len=8 curlen=8 curoffs=0
1685992014.561455 ehci_reset_sqtd_chain#1@0:       buffer[0/1] 0x00000001 0x1d725000
1685992014.561455 ehci_reset_sqtd_chain#1@0:     va 0xffffb9023a92ef80 pa 0x11d725f80 len 8
1685992014.561455 ehci_dump_sqh#2@0: called!
1685992014.561456 ehci_dump_sqh#2@0:     link 0x00000001 (T = 1):
1685992014.561456 ehci_dump_sqh#2@0:         ITD  = 1  QH   = 0  SITD = 0  FSTN = 0
1685992014.561456 ehci_dump_sqh#2@0:     link 0xcad98f80 (T = 0):
1685992014.561456 ehci_dump_qtd#7@0: called!
1685992014.561456 ehci_dump_sqtds#6@0: called!
1685992014.561456 ehci_dump_sqtd#6@0: called!
1685992014.561456 ehci_dump_qtd#8@0: called!
1685992014.561460 ehci_device_clear_toggle#1@0: called!
1685992014.561460 ehci_device_clear_toggle#1@0: epipe=0xffff82d724667e00 status=0x00000000
1685992014.561462 ehci_alloc_sqtd#1@0: called!
1685992014.561463 ehci_alloc_sqtd#2@0: called!
1685992014.561464 ehci_device_ctrl_start#1@0: called!
1685992014.561464 ehci_device_ctrl_start#1@0: type=0x02, request=0x01, wValue=0x0000, wIndex=0x0081
1685992014.561464 ehci_device_ctrl_start#1@0: len=0, addr=4, endpt=0
1685992014.561464 ehci_device_ctrl_start#1@0: setup 0xffffb90238f76d80 status 0xffffb90238f76c80 data 0
1685992014.561465 ehci_dump_sqh#3@0: called!
1685992014.561465 ehci_dump_sqh#3@0:     link 0xcad96e82 (T = 0):
1685992014.561465 ehci_dump_sqh#3@0:         ITD  = 0  QH   = 1  SITD = 0  FSTN = 0
1685992014.561465 ehci_dump_sqh#3@0:     link 0xcad98d80 (T = 0):
1685992014.561465 ehci_dump_qtd#9@0: called!
1685992014.561465 ehci_dump_sqtds#7@0: called!
1685992014.561466 ehci_dump_sqtd#7@0: called!
1685992014.561466 ehci_dump_qtd#10@0: called!
1685992014.561466 ehci_dump_sqtd#8@0: called!
1685992014.561466 ehci_dump_qtd#11@0: called!
1685992014.561908 ehci_intr#2@0: called!
1685992014.561908 ehci_intr1#2@0: called!
1685992014.561909 ehci_intr1#2@0: sc=0xffff82d6f556d000 intrs=0x1(0xc001) eintrs=0x1
1685992014.561910 ehci_intr1#2@0: INT=1  ERRINT=0
1685992014.561911 ehci_softintr#2@0: called!
1685992014.561911 ehci_check_qh_intr#5@0: called!
1685992014.561912 ehci_dump_sqtds#8@0: called!
1685992014.561912 ehci_dump_sqtd#9@0: called!
1685992014.561912 ehci_dump_qtd#12@0: called!
1685992014.561912 ehci_check_qh_intr#6@0: called!
1685992014.561913 ehci_dump_sqtds#9@0: called!
1685992014.561913 ehci_dump_sqtd#10@0: called!
1685992014.561913 ehci_dump_qtd#13@0: called!
1685992014.561913 ehci_check_qh_intr#7@0: called!
1685992014.561913 ehci_dump_sqtds#10@0: called!
1685992014.561913 ehci_dump_sqtd#11@0: called!
1685992014.561914 ehci_dump_qtd#14@0: called!
1685992014.561914 ehci_check_qh_intr#8@0: called!
1685992014.561914 ehci_dump_sqtds#11@0: called!
1685992014.561914 ehci_dump_sqtd#12@0: called!
1685992014.561914 ehci_dump_qtd#15@0: called!
1685992014.561914 ehci_check_qh_intr#9@0: called!
1685992014.561915 ehci_idone#2@0: called!
1685992014.561915 ehci_idone#2@0: ex=0xffff82d6f57b1908
1685992014.561916 ehci_idone#2@0: xfer=0xffff82d6f57b1908, pipe=0xffff82d71cde0500 ready
1685992014.561916 ehci_dump_sqtds#12@0: called!
1685992014.561916 ehci_dump_sqtd#13@0: called!
1685992014.561916 ehci_dump_qtd#16@0: called!
1685992014.561916 ehci_dump_sqtd#14@0: called!
1685992014.561917 ehci_dump_qtd#17@0: called!
1685992014.561917 ehci_idone#2@0: len=0 actlen=0 status=0x00008d00
1685992014.561917 ehci_idone#2@0: ex=0xffff82d6f57b1908 done
1685992014.561918 ehci_device_ctrl_done#1@0: called!
1685992014.561918 ehci_device_ctrl_done#1@0: xfer=0xffff82d6f57b1908
1685992014.561918 ehci_device_ctrl_done#1@0: length=0
1685992014.561921 ehci_free_sqtds#1@0: called!
1685992014.561921 ehci_free_sqtds#1@0: exfer=0xffff82d6f57b1908

This keyboard (Leopold FC750R PD) works nice with Linux and OpenBSD, but does
*not* work under NetBSD.
>How-To-Repeat:
1. Plug in Leopold FC750R PD keyboard via USB
2. Press a key
3. Observe system message buffer (dmesg)
>Fix:
USB 1.1 devices interact with the USB 2.0 host controller through a transaction
translator (implemented in a USB 2.0 hub) which converts low-/full-speed
transactions into high-speed split transactions. The bug described above is
caused by the EHCI driver incorrectly scheduling split transactions for
full-/low-speed interrupt transactions. ehci_open function schedules
start-split to micro-frame Y1, the full-/low-speed transaction to micro-frame
Y2 and *one* complete-split to micro-frame Y3. (One H-Frame has 8 micro-frames
indexed Y0 to Y7.) USB 2.0 specifies (section 11.8.4; paragraph 3.b) that a
compete-split must be scheduled for each of the 3 micro-frames following the
micro-frame the low-/full-speed transaction is scheduled for:

"For interrupt IN/OUT full-/low-speed transactions, the host must schedule a
complete-split transaction in each of the two microframes following the first
microframe in which the full-/low-speed transaction is budgeted. An additional
complete-split must also be scheduled in the third following microframe unless
the full-/low-speed transaction was budgeted to start in microframe Y6."

As the current implementation has the full-/low-speed transaction scheduled to
micro-frame Y2 (and *not* micro-frame Y6), complete-splits should be scheduled
for micro-frames Y3, Y4 and Y5.

This fixes my keyboard:

--- a/sys/dev/usb/ehci.c
+++ b/sys/dev/usb/ehci.c
@@ -2039,7 +2039,7 @@ ehci_open(struct usbd_pipe *pipe)
 			    EHCI_QH_SET_PORT(hshubport) |
 			    EHCI_QH_SET_HUBA(hshubaddr) |
 			    (xfertype == UE_INTERRUPT ?
-				 EHCI_QH_SET_CMASK(0x08) : 0)
+				 EHCI_QH_SET_CMASK(0x38) : 0)
 			);
 		sqh->qh.qh_curqtd = EHCI_NULL;
 		/* Fill the overlay qTD */

>Release-Note:

>Audit-Trail:

Responsible-Changed-From-To: kern-bug-people->skrll
Responsible-Changed-By: skrll@NetBSD.org
Responsible-Changed-When: Sun, 30 Jul 2023 09:20:51 +0000
Responsible-Changed-Why:
Take


State-Changed-From-To: open->feedback
State-Changed-By: skrll@NetBSD.org
State-Changed-When: Sun, 30 Jul 2023 12:19:01 +0000
State-Changed-Why:
I committed a functionally equivalent diff, but used __BITS and added
a couple of comments.
Thanks for the PR.


State-Changed-From-To: feedback->pending-pullups
State-Changed-By: skrll@NetBSD.org
State-Changed-When: Wed, 02 Aug 2023 08:00:25 +0000
State-Changed-Why:
[pullup-10 #301]
[pullup-9 #1698]
[pullup-8 #1877]


From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/57518 CVS commit: [netbsd-10] src/sys/dev/usb
Date: Wed, 2 Aug 2023 10:20:38 +0000

 Module Name:	src
 Committed By:	martin
 Date:		Wed Aug  2 10:20:38 UTC 2023

 Modified Files:
 	src/sys/dev/usb [netbsd-10]: ehci.c

 Log Message:
 Pull up following revision(s) (requested by skrll in ticket #301):

 	sys/dev/usb/ehci.c: revision 1.317

 PR 57518: usb keyboard causes host controller to miss microframe

 As per the USB 2.0 specification section 11.18.4; paragraph 3.b
 For interrupt IN/OUT full-/low-speed transactions, the host must  schedule a
 complete-split transaction in each of the two microframes following the
 first microframe in which the full-/low-speed transaction is budgeted. An
 additional complete-split must also be scheduled in the third following
 microframe unless the full-/low-speed transaction was budgeted to start
 in microframe Y6.


 To generate a diff of this commit:
 cvs rdiff -u -r1.315 -r1.315.2.1 src/sys/dev/usb/ehci.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/57518 CVS commit: [netbsd-9] src/sys/dev/usb
Date: Wed, 2 Aug 2023 10:22:13 +0000

 Module Name:	src
 Committed By:	martin
 Date:		Wed Aug  2 10:22:13 UTC 2023

 Modified Files:
 	src/sys/dev/usb [netbsd-9]: ehci.c

 Log Message:
 Pull up following revision(s) (requested by skrll in ticket #1698):

 	sys/dev/usb/ehci.c: revision 1.317

 PR 57518: usb keyboard causes host controller to miss microframe

 As per the USB 2.0 specification section 11.18.4; paragraph 3.b
 For interrupt IN/OUT full-/low-speed transactions, the host must  schedule a
 complete-split transaction in each of the two microframes following the
 first microframe in which the full-/low-speed transaction is budgeted. An
 additional complete-split must also be scheduled in the third following
 microframe unless the full-/low-speed transaction was budgeted to start
 in microframe Y6.


 To generate a diff of this commit:
 cvs rdiff -u -r1.267.2.6 -r1.267.2.7 src/sys/dev/usb/ehci.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

From: "Martin Husemann" <martin@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/57518 CVS commit: [netbsd-8] src/sys/dev/usb
Date: Wed, 2 Aug 2023 10:24:17 +0000

 Module Name:	src
 Committed By:	martin
 Date:		Wed Aug  2 10:24:17 UTC 2023

 Modified Files:
 	src/sys/dev/usb [netbsd-8]: ehci.c

 Log Message:
 Pull up following revision(s) (requested by skrll in ticket #1877):

 	sys/dev/usb/ehci.c: revision 1.317

 PR 57518: usb keyboard causes host controller to miss microframe

 As per the USB 2.0 specification section 11.18.4; paragraph 3.b
 For interrupt IN/OUT full-/low-speed transactions, the host must  schedule a
 complete-split transaction in each of the two microframes following the
 first microframe in which the full-/low-speed transaction is budgeted. An
 additional complete-split must also be scheduled in the third following
 microframe unless the full-/low-speed transaction was budgeted to start
 in microframe Y6.


 To generate a diff of this commit:
 cvs rdiff -u -r1.254.8.7 -r1.254.8.8 src/sys/dev/usb/ehci.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

State-Changed-From-To: pending-pullups->closed
State-Changed-By: skrll@NetBSD.org
State-Changed-When: Wed, 02 Aug 2023 10:45:20 +0000
State-Changed-Why:
All pullups processed.


>Unformatted:

Home	PR Database Search