NetBSD Problem Report #48237

From Wolfgang.Stukenbrock@nagler-company.com  Tue Sep 24 10:31:50 2013
Return-Path: <Wolfgang.Stukenbrock@nagler-company.com>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
	(using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "Postmaster NetBSD.org" (verified OK))
	by mollari.NetBSD.org (Postfix) with ESMTPS id D670371FEA
	for <gnats-bugs@gnats.NetBSD.org>; Tue, 24 Sep 2013 10:31:50 +0000 (UTC)
Message-Id: <20130924103140.7C6F5123B93@test-s0.nagler-company.com>
Date: Tue, 24 Sep 2013 12:31:40 +0200 (CEST)
From: Wolfgang.Stukenbrock@nagler-company.com
Reply-To: Wolfgang.Stukenbrock@nagler-company.com
To: gnats-bugs@gnats.NetBSD.org
Subject: NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
X-Send-Pr-Version: 3.95

>Number:         48237
>Category:       kern
>Synopsis:       NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    kern-bug-people
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Tue Sep 24 10:35:00 +0000 2013
>Closed-Date:    Fri Aug 23 07:13:29 +0000 2019
>Last-Modified:  Fri Aug 23 07:13:29 +0000 2019
>Originator:     Dr. Wolfgang Stukenbrock
>Release:        NetBSD 6.1
>Organization:
Dr. Nagler & Company GmbH
>Environment:


System: NetBSD test-s0 5.1.2 NetBSD 5.1.2 (NSW-WS) #3: Fri Dec 21 15:15:43 CET 2012 wgstuken@test-s0:/usr/src/sys/arch/amd64/compile/NSW-WS amd64
Architecture: x86_64
Machine: amd64
>Description:
	In 5.x every thing was fine.
	Now in 6.1 (I think 6.x is affected) our old USB-modem devices are no
	longer detected.
	E.g. 'uhub1: device problem, disabling port 2' is reported - the hub
	and the port number vary depending on the connection.
	The Modem is an "old" full-speed device according to the hand-over
	message from the ehci.
	A Mouse (low-speed device) is detected correctly.
	'uhidev0: Microsoft Microsoft 5-Button Mouse with IntelliEye(TM), rev 1.10/3.00, addr 2, iclass 3/1'
	I've enabled some debugging, but I don't understand the output.
	The main problem when enabling USB_DBUG is,
	that the serial console is to slow, so everything seems to run into
	timeout and nothing connects anymore ...
	I've tried USB_DEBUG, but commented out UHCI_DEBUG in usb.h.
	Now the mouse is attached again and the output below is on console if
	on modem is connected.

	If anybody can tell me what to do for additional debugging I'm willing
	to do it, but I need some help with this.
>How-To-Repeat:
	Setup 6.1 and connect an USB 1.0 device like
	'Lucent Technologies, Inc. ELSA Modem Board, rev 1.00/1.00'
	At least this type of device is not detected correctly.
>Fix:
	not realy known till now.
	The fix mentioned in PR 46696 discusion (even if expanded to full-speed
	devices or all devices) does not solve the problem.
	I'm not shure what is gooing on, but for USB 1.x devices the initial packet
	may not exceed 8 Bytes as far as I know, so the 64-Byte change should never
	reach USB 1.x devices. So the check on the speed only (not the version)
	sounds like an incomplete way in PR 46696 ...


	Added output from connection try:
usb_transfer_complete: pipe=0xc1729ccc xfer=0xc14da2b4 status=0 actlen=1
usb_transfer_complete: repeat=1 new head=0xc14da2b4
uhub_intr: sc=0xc165f4a8
usb_needs_explore
usb_event_thread: woke up
usb_discover
uhub_explore dev=0xc1693a0c addr=1
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
uhub_explore: status change hub=1 port=2
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
uhub_explore: port=2 !CURRENT_CONNECT_STATUS
usb_transfer_complete: pipe=0xc171c514 xfer=0xc14da014 status=0 actlen=2
usb_transfer_complete: repeat=1 new head=0xc14da014
uhub_intr: sc=0xc165f390
usb_needs_explore
usb_needs_explore
usb_event_thread: woke up
usb_discover
uhub_explore dev=0xc169388c addr=1
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
uhub_explore: status change hub=1 port=4
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
usb_event_thread: woke up
usb_discover
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_event_thread: woke up
usb_discover
ehci0: handing over full speed device on port 4 to uhci1
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=0
usb_transfer_complete: pipe=0xc171c514 xfer=0xc14da014 status=0 actlen=2
usb_transfer_complete: repeat=1 new head=0xc14da014
uhub_intr: sc=0xc165f390
usb_needs_explore
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usb_transfer_complete: pipe=0xc1729ccc xfer=0xc14da2b4 status=0 actlen=1
usb_transfer_complete: repeat=1 new head=0xc14da2b4
uhub_intr: sc=0xc165f4a8
usb_needs_explore
usbd_free_xfer: 0xc1757b7c
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
uhub_explore dev=0xc169388c addr=1
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
uhub_explore: status change hub=1 port=4
usb_transfer_complete: pipe=0xc1729ccc xfer=0xc14da2b4 status=0 actlen=1
usb_transfer_complete: repeat=1 new head=0xc14da2b4
uhub_intr: sc=0xc165f4a8
usbd_alloc_xfer() = 0xc1757b7c
usbd_transfer: xfer=0xc1757b7c, flags=0x2, pipe=0xc171cc34, running=0
usbd_dump_queue: pipe=0xc171cc34
usb_insert_transfer: pipe=0xc171cc34 running=0 timeout=5000
usb_transfer_complete: pipe=0xc171cc34 xfer=0xc1757b7c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc171cc34, xfer=0x0
usbd_free_xfer: 0xc1757b7c
uhub_explore: port=4 !CURRENT_CONNECT_STATUS
usb_event_thread: woke up
usb_discover
uhub_explore dev=0xc1693a0c addr=1
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
uhub_explore: status change hub=1 port=2
usbd_alloc_xfer() = 0xc1757e1c
usb_transfer_complete: pipe=0xc1729ccc xfer=0xc14da2b4 status=0 actlen=1
usb_transfer_complete: repeat=1 new head=0xc14da2b4
uhub_intr: sc=0xc165f4a8
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729ccc xfer=0xc14da2b4 status=0 actlen=1
usb_transfer_complete: repeat=1 new head=0xc14da2b4
uhub_intr: sc=0xc165f4a8
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_allocmem: use frag=0xd99e2d80 size=4
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=4
usb_freemem: frag=0xd99e2d80
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_new_device bus=0xc169200c port=2 depth=1 speed=2
usb_allocmem: use frag=0xd99e2d80 size=8
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x6, pipe=0xc17294ec, running=0
usbd_dump_queue: pipe=0xc17294ec
usb_allocmem: use frag=0xd99e2d40 size=64
usb_insert_transfer: pipe=0xc17294ec running=0 timeout=5000
usb_schedsoftintr: polling=0
usb_transfer_complete: pipe=0xc17294ec xfer=0xc1757e1c status=0 actlen=18
usb_freemem: frag=0xd99e2d40
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc17294ec, xfer=0x0
usbd_free_xfer: 0xc1757e1c
ini-desc 0 actlen 18
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_allocmem: use frag=0xd99e2d40 size=4
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=4
usb_freemem: frag=0xd99e2d40
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_new_device: adding unit addr=2, rev=100, class=2, subclass=0, protocol=0, maxpacket=8, len=18, speed=2
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc17294ec, running=0
usbd_dump_queue: pipe=0xc17294ec
usb_insert_transfer: pipe=0xc17294ec running=0 timeout=5000
usb_schedsoftintr: polling=0
usb_transfer_complete: pipe=0xc17294ec xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc17294ec, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc17294ec, running=0
usbd_dump_queue: pipe=0xc17294ec
usb_allocmem: use frag=0xd99e2d40 size=18
usb_insert_transfer: pipe=0xc17294ec running=0 timeout=5000
usb_schedsoftintr: polling=0
usb_transfer_complete: pipe=0xc17294ec xfer=0xc1757e1c status=17 actlen=0
usb_freemem: frag=0xd99e2d40
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc17294ec, xfer=0x0
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc17294ec, running=0
usbd_dump_queue: pipe=0xc17294ec
usb_allocmem: use frag=0xd99e2d40 size=2
usb_insert_transfer: pipe=0xc17294ec running=0 timeout=5000
usb_schedsoftintr: polling=0
usb_transfer_complete: pipe=0xc17294ec xfer=0xc1757e1c status=17 actlen=0
usb_freemem: frag=0xd99e2d40
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc17294ec, xfer=0x0
usbd_do_request_flags_pipe: returning err=STALLED
usbd_free_xfer: 0xc1757e1c
usbd_remove_device: 0xc1ff698c
usbd_ar_pipe: pipe=0xc17294ec
usbd_dump_queue: pipe=0xc17294ec
uhub_explore: usbd_new_device failed, error=STALLED
uhub1: device problem, disabling port 2
usbd_alloc_xfer() = 0xc1757e1c
usbd_transfer: xfer=0xc1757e1c, flags=0x2, pipe=0xc1729f6c, running=0
usbd_dump_queue: pipe=0xc1729f6c
usb_insert_transfer: pipe=0xc1729f6c running=0 timeout=5000
usb_transfer_complete: pipe=0xc1729f6c xfer=0xc1757e1c status=0 actlen=0
usb_transfer_complete: repeat=0 new head=0x0
usbd_start_next: pipe=0xc1729f6c, xfer=0x0
usbd_free_xfer: 0xc1757e1c
usb_event_thread: woke up
usb_discover

>Release-Note:

>Audit-Trail:
From: Wolfgang Stukenbrock <wolfgang.stukenbrock@nagler-company.com>
To: gnats-bugs@NetBSD.org
Cc: 
Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
Date: Tue, 24 Sep 2013 16:38:00 +0200

 Hi again,

 I've done some additional debugging till now.

 The problem is not sensitive to the size of the first transfer chunk as 
 mentioned before - so PR 46696 seems to describe the a different problem.

 What happens?

 When a new device is found in usb_subr.c a transfer is done and only 8 
 bytes are expected back.
 After that the address for the new device is set on the device and then 
 the whole description structure is retrieved again.
 After that the default-pipe is killed and reopened again.

 Now when getting the description again, the transfer gets STALLED - the 
 first status seen by the system. (STALLED is returned.)

 In 5.x there was a different order: first get the description and than 
 set the address and then kill pipe etc.
 If I change it back to this order, I get some data back (18 bytes as 
 acpected) but the transfer still gets STALLED and now IOERROR is 
 returned. This looks much better but still does not work - perhaps some 
 settings related to the 64 bytes instead of the 8 used in 5.x may be the 
 reason.

 I'm not realy confimed with the order of actions on the USB bus, but it 
 looks wrong to me to change the address but reuse the old pipe for the 
 description prior destroy/reopen of the pipe.

 I hope some one has the time to look at this, because this problem stops 
 me from upgrading to 6.x, because I need the old USB devices ...

 best regards
 W. Stukenbrock

 gnats-admin@NetBSD.org wrote:

 > Thank you very much for your problem report.
 > It has the internal identification `kern/48237'.
 > The individual assigned to look at your
 > report is: kern-bug-people. 
 > 
 > 
 >>Category:       kern
 >>Responsible:    kern-bug-people
 >>Synopsis:       NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
 >>Arrival-Date:   Tue Sep 24 10:35:00 +0000 2013
 >>
 > 
 > 
 > 
 > 
 > Received: from DB3PR07MB172.eurprd07.prod.outlook.com (10.242.132.151) by
 >  DB3PR07MB169.eurprd07.prod.outlook.com (10.242.132.141) with Microsoft SMTP
 >  Server (TLS) id 15.0.775.9 via Mailbox Transport; Tue, 24 Sep 2013 10:36:16
 >  +0000
 > Received: from DB3PR07MB090.eurprd07.prod.outlook.com (10.242.147.143) by
 >  DB3PR07MB172.eurprd07.prod.outlook.com (10.242.132.151) with Microsoft SMTP
 >  Server (TLS) id 15.0.775.9; Tue, 24 Sep 2013 10:36:15 +0000
 > Received: from DB3PRD0711HT002.eurprd07.prod.outlook.com (10.255.183.35) by
 >  DB3PR07MB090.eurprd07.prod.outlook.com (10.242.147.143) with Microsoft SMTP
 >  Server (TLS) id 15.0.775.9; Tue, 24 Sep 2013 10:36:14 +0000
 > Received: from DB3PRD0711HT004.eurprd07.prod.outlook.com (10.255.183.37) by
 >  DB3PRD0711HT002.eurprd07.prod.outlook.com (10.255.183.35) with Microsoft SMTP
 >  Server (TLS) id 14.16.359.1; Tue, 24 Sep 2013 10:36:13 +0000
 > Received: from mail198-co9-R.bigfish.com (207.46.163.20) by
 >  DB3PRD0711HT004.eurprd07.prod.outlook.com (10.255.183.37) with Microsoft SMTP
 >  Server (TLS) id 14.16.359.1; Tue, 24 Sep 2013 10:36:12 +0000
 > Received: from mail198-co9 (localhost [127.0.0.1])	by
 >  mail198-co9-R.bigfish.com (Postfix) with ESMTP id 09DFF88004D	for
 >  <wolfgang.stukenbrock@nagler-company.com>; Tue, 24 Sep 2013 10:35:11 +0000
 >  (UTC)
 > X-Forefront-Antispam-Report: CIP:212.185.86.227;KIP:(null);UIP:(null);IPV:NLI;H:e002.nagler-company.com;RD:e002.nagler-company.com;EFVD:NLISFV:NSPM;SFS:(36882001)(45984002)(189002)(199002)(49866001)(47736001)(74706001)(50986001)(83322001)(47976001)(80976001)(74876001)(81686001)(46386002)(48376002)(74366001)(81816001)(79102001)(50466002)(16276001)(65816001)(6806004)(52956002)(74662001)(54316002)(74502001)(47446002)(59766001)(56776001)(77982001)(20776003)(76796001)(46102001)(80022001)(33656001)(63696002)(76786001)(76482001)(47776003)(70486001)(81542001)(42186004)(69226001)(43066001)(54356001)(51856001)(81342001)(83072001)(4396001)(56816003)(77096001)(45336002);DIR:INB;SFP:;SCL:1;SRVR:DB3PR07MB090;H:DB3PRD0711HT002.eurprd07.prod.outlook.com;CLIP:10.236.132.251;FPR:;RD:e002.nagler-company.com;MX:1;A:1;LANG:en;
 > X-SpamScore: -7
 > X-BigFish: ps-7(zz11f6Nzz1f42he68I208ch1ee6h1de0h1fdah2073h1202h1e76h1d1ah1d2ah1fc6hzzz2dh2a8h839hd25h107ah10d2h11b5h121eh1288h12a5h12a9h12bdh12e5h137ah13b6h13eah1441h14afh1537h153bh162dh1631h1758h18e1h1946h19b5h1b0ah1b88h1d0ch1d2eh1d3fh1dfeh1dffh1e1dh1fe8h1ff5h1155h)
 > X-FFO-Routing-Override: nagler-company.com%inboundsmtpprofile-282668.customer.frontbridge.com;
 > Received: from mail198-co9 (localhost.localdomain [127.0.0.1]) by mail198-co9
 >  (MessageSwitch) id 1380018907853276_25261; Tue, 24 Sep 2013 10:35:07 +0000
 >  (UTC)
 > Received: from CO9EHSMHS001.bigfish.com (unknown [10.236.132.251])	by
 >  mail198-co9.bigfish.com (Postfix) with ESMTP id C2116500048	for
 >  <wolfgang.stukenbrock@nagler-company.com>; Tue, 24 Sep 2013 10:35:07 +0000
 >  (UTC)
 > Received: from e002.nagler-company.com (212.185.86.227) by
 >  CO9EHSMHS001.bigfish.com (10.236.130.11) with Microsoft SMTP Server (TLS) id
 >  14.16.227.3; Tue, 24 Sep 2013 10:35:07 +0000
 > Received: from mollari.NetBSD.org (mollari.netbsd.org [149.20.53.80])	by
 >  e002.nagler-company.com (8.14.5/8.14.5) with ESMTP id r8OAZ1xb012706	for
 >  <Wolfgang.Stukenbrock@nagler-company.com>; Tue, 24 Sep 2013 12:35:04 +0200
 >  (CEST)
 > Received: by mollari.NetBSD.org (Postfix, from userid 31008)	id 9AECE72628;
 >  Tue, 24 Sep 2013 10:35:00 +0000 (UTC)
 > From: <gnats-admin@NetBSD.org>
 > To: <Wolfgang.Stukenbrock@nagler-company.com>
 > Reply-To: <gnats-bugs@NetBSD.org>
 > Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
 > References: <pr-kern-48237@gnats.netbsd.org> <20130924103140.7C6F5123B93@test-s0.nagler-company.com>
 > In-Reply-To: <20130924103140.7C6F5123B93@test-s0.nagler-company.com>
 > Message-ID: <20130924103500.9AECE72628@mollari.NetBSD.org>
 > Date: Tue, 24 Sep 2013 10:35:00 +0000
 > Content-Type: text/plain
 > Return-Path: gnats@NetBSD.org
 > X-MS-Exchange-Organization-MessageDirectionality: Incoming
 > X-MS-Exchange-Organization-SCL: 1
 > X-MS-Exchange-Organization-AVStamp-Mailbox: MSFTFF;1;0;0 0 0
 > X-MS-Exchange-Organization-Network-Message-Id: cfa645ef-ff8b-4bea-9deb-08d087290728
 > X-MS-Exchange-Organization-AVStamp-Service: 1.0
 > Received-SPF: None (: NetBSD.org does not designate permitted sender hosts)
 > X-MS-Exchange-Organization-AuthSource: DB3PRD0711HT004.eurprd07.prod.outlook.com
 > X-MS-Exchange-Organization-AuthAs: Anonymous
 > MIME-Version: 1.0
 > 
 > Thank you very much for your problem report.
 > It has the internal identification `kern/48237'.
 > The individual assigned to look at your
 > report is: kern-bug-people. 
 > 
 > 
 >>Category:       kern
 >>Responsible:    kern-bug-people
 >>Synopsis:       NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
 >>Arrival-Date:   Tue Sep 24 10:35:00 +0000 2013
 >>
 > 
 > 


 -- 


 Dr. Nagler & Company GmbH
 Hauptstraße 9
 92253 Schnaittenbach

 Tel. +49 9622/71 97-42
 Fax +49 9622/71 97-50

 Wolfgang.Stukenbrock@nagler-company.com
 http://www.nagler-company.com


 Hauptsitz: Schnaittenbach
 Handelregister: Amberg HRB
 Gerichtsstand: Amberg
 Steuernummer: 201/118/51825
 USt.-ID-Nummer: DE 273143997
 Geschäftsführer: Dr. Martin Nagler, Prof. Dr. Dr. Karl-Kuno Kunze


From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc: Wolfgang.Stukenbrock@nagler-company.com, kern-bug-people@netbsd.org, 
 gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device
 (umodem)
Date: Tue, 24 Sep 2013 16:32:12 +0100

 On 09/24/13 11:35, Wolfgang.Stukenbrock@nagler-company.com wrote:
 >> Number:         48237
 >> Category:       kern
 >> Synopsis:       NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
 >>

 Try applying the changes in

 http://releng.netbsd.org/cgi-bin/req-6.cgi?show=950

 to your netbsd-6 tree.

 Nick

From: Wolfgang Stukenbrock <wolfgang.stukenbrock@nagler-company.com>
To: gnats-bugs@NetBSD.org
Cc: kern-bug-people@NetBSD.org, gnats-admin@NetBSD.org, netbsd-bugs@NetBSD.org
Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
Date: Wed, 25 Sep 2013 11:01:19 +0200

 This is a multi-part message in MIME format.
 --------------010806070309050602060802
 Content-Type: text/plain; charset=us-ascii; format=flowed
 Content-Transfer-Encoding: 7bit

 Hi,

 I've added the mentioned changes.
 This means the usb_memsync call changes (and some other minor things like
 USB_USE_SOFTINTR elimination etc.)
 My base version is the 1.212 for uhci.c from the release tree.
 So I've not added the switch to use the mutex-stuff and/or the 
 MP-related changes.
 (remark: the system I'm trying to get it up again is a i386 Celeron 
 system. But the problem is also present on amd64 architecture.)

 Accedently patching ehci.c and uhci.c with the addresses changes does 
 not change a lot.

 For better explanation some debug-output I've added to the code.
 (The "--- status" line is in uhci_idone() for each status extracted in 
 the "non-ISO"-loop.)

 With 64-Byte initial transfer and first setting Address (2) to the device:

 ehci0: handing over full speed device on port 4 to uhci1
 usbd_new_device bus=0xc168e00c port=2 depth=1 speed=2
 usbd_new_device: myhsport = NULL
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x38000007
 uhci_idone: actlen=8, status=0x0
 usbd_new_device: addr=2, getting first desc done
 usbd_new_device: adding unit addr=2, rev=100, class=2, subclass=0, 
 protocol=0, maxpacket=8, len=18, speed=2
 usbd_new_device: setting device address=2
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x190007ff
 uhci_idone: actlen=0, status=0x0
 usbd_get_device_desc:
 usbd_get_desc: type=1, index=0, len=18
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x450007
 uhci_idone: actlen=0, status=0x400000
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x450007
 uhci_idone: actlen=0, status=0x400000
 usbd_new_device: addr=2, getting full desc failed
 usbd_remove_device: 0xc1fc6b8c
 uhub1: device problem, disabling port 2

 The initial retrieval of the description (8 Bytes) seems to work.
 Setting Address = 2 seems to work too.
 But trying to get the description (18 Bytes again) funs immediately int 
 STALLED (0x500000 in the status)

 Trying "the same with address setting and descrition retrival in the 
 order as done in 5.1.2 (still with 64-Bytes initial request:)

 ehci0: handing over full speed device on port 4 to uhci1
 usbd_new_device bus=0xc168e00c port=2 depth=1 speed=2
 usbd_new_device: myhsport = NULL
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x38000007
 uhci_idone: actlen=8, status=0x0
 ini-desc 0 actlen 8
 usbd_new_device: addr=2, getting first desc done
 usbd_new_device: adding unit addr=2, rev=100, class=2, subclass=0, 
 protocol=0, maxpacket=8, len=18, speed=2
 usbd_get_device_desc:
 usbd_get_desc: type=1, index=0, len=18
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x18000007
   ---- status 0x18000007
   ---- status 0x18500001
 uhci_idone: actlen=18, status=0x500000
 usbd_new_device: addr=2, getting full desc failed
 usbd_remove_device: 0xc1fbeb8c
 uhub1: device problem, disabling port 2


 It looks like the 18 Bytes are transfered, but then it still gets 
 STALLED ?!?!?!?!? Why? Are more bytes expected?

 And now with 8 Bytes initial request:

 ehci0: handing over full speed device on port 4 to uhci1
 usbd_new_device bus=0xc168e00c port=2 depth=1 speed=2
 usbd_new_device: myhsport = NULL
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x38000007
   ---- status 0x38000007
   ---- status 0x38000001
 uhci_idone: actlen=18, status=0x0
 usbd_new_device: addr=2, getting first desc done
 usbd_new_device: adding unit addr=2, rev=100, class=2, subclass=0, 
 protocol=0, maxpacket=8, len=18, speed=2
 usbd_get_device_desc:
 usbd_get_desc: type=1, index=0, len=18
 uhci_idone: ii=0xc1753e98
 uhci_idone: ii=0xc1753e98, xfer=0xc1753e1c, pipe=0xc17254ec ready
   ---- status 0x18000007
   ---- status 0x180007ff
   ---- status 0x18000007
   ---- status 0x18500001
 uhci_idone: actlen=10, status=0x500000
 usbd_new_device: addr=2, getting full desc failed
 usbd_remove_device: 0xc1fd858c
 uhub1: device problem, disabling port 2

 Here we already got 18 bytes the first time and then only 10 bytes - 
 does the initial transfer size affect this transfer ??? Why do we get 
 more data???



 The sequence - with slitly different printf's in the code on a 5.1.2 
 system (amd64 this time - no additional i386 system for testing 
 currently available.) Here we get the communication up and running with 
 the same HW-device ...

 usbd_get_desc: type=1, index=0, len=8
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff80000907b900 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x190007ff
 uhci_idone: actlen=8, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=8
 usbd_get_device_desc:
 usbd_get_desc: type=1, index=0, len=18
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff80000907b900 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000001
   --- status 0x190007ff
 uhci_idone: actlen=18, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=18
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff80000907b900 ready
   --- status 0x18000007
   --- status 0x190007ff
 uhci_idone: actlen=0, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=0
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=2, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=2
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000005
   --- status 0x190007ff
 uhci_idone: actlen=6, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=6
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=2, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=2
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000003
   --- status 0x190007ff
 uhci_idone: actlen=52, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=52
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=2, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=2
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=34, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=34
 usbd_get_config_desc: confidx=0
 usbd_get_desc: type=2, index=0, len=9
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000000
   --- status 0x190007ff
 uhci_idone: actlen=9, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=9
 usbd_get_desc: type=2, index=0, len=41
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000000
   --- status 0x190007ff
 uhci_idone: actlen=41, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=41
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x190007ff
 uhci_idone: actlen=0, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=0
 usbd_get_config_desc: confidx=1
 usbd_get_desc: type=2, index=1, len=9
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000000
   --- status 0x190007ff
 uhci_idone: actlen=9, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=9
 usbd_get_desc: type=2, index=1, len=62
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000005
   --- status 0x190007ff
 uhci_idone: actlen=62, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=62
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x190007ff
 uhci_idone: actlen=0, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=0
 usbd_get_config_desc: confidx=0
 usbd_get_desc: type=2, index=0, len=9
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000000
   --- status 0x190007ff
 uhci_idone: actlen=9, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=9
 usbd_get_desc: type=2, index=0, len=41
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000007
   --- status 0x18000000
   --- status 0x190007ff
 uhci_idone: actlen=41, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=41
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x190007ff
 uhci_idone: actlen=0, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=0
 ugen0 at uhub4 port 1ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=2, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=2
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000003
   --- status 0x190007ff
 uhci_idone: actlen=52, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=52
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=2, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=2
 ctrltrans - 0xffff800007f9ba00
   --- start timeout 5000
 uhci_idone: ii=0xffff800007f9bae0
 uhci_idone: ii=0xffff800007f9bae0, xfer=0xffff800007f9ba00, 
 pipe=0xffff800008448e00 ready
   --- status 0x18000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000007
   --- status 0x38000001
   --- status 0x190007ff
 uhci_idone: actlen=34, status=0x0
 ctrl-done 0xffff800007f9ba00
 uhci_device_ctrl_done: length=34

 ugen0: Lucent Technologies, Inc. ELSA Modem Board, rev 1.00/1.00, addr 2

 remark: on this system umodem is not configured, so the device dropped 
 into ugen, but the problem happnes during the first transfers while 
 getting the device description.




 Help !!!
 Any additional idea what may be wrong?

 I add the applied diffs as attachments, but they look good for me.





 Nick Hudson wrote:

 > The following reply was made to PR kern/48237; it has been noted by GNATS.
 > 
 > From: Nick Hudson <skrll@netbsd.org>
 > To: gnats-bugs@NetBSD.org
 > Cc: Wolfgang.Stukenbrock@nagler-company.com, kern-bug-people@netbsd.org, 
 >  gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
 > Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device
 >  (umodem)
 > Date: Tue, 24 Sep 2013 16:32:12 +0100
 > 
 >  On 09/24/13 11:35, Wolfgang.Stukenbrock@nagler-company.com wrote:
 >  >> Number:         48237
 >  >> Category:       kern
 >  >> Synopsis:       NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
 >  >>
 >  
 >  Try applying the changes in
 >  
 >  http://releng.netbsd.org/cgi-bin/req-6.cgi?show=950
 >  
 >  to your netbsd-6 tree.
 >  
 >  Nick
 >  


 --------------010806070309050602060802
 Content-Type: text/plain;
  name="ehci.c-diff"
 Content-Transfer-Encoding: 7bit
 Content-Disposition: inline;
  filename="ehci.c-diff"

 --- ehci.c	2013/09/25 07:04:36	1.1
 +++ ehci.c	2013/09/25 08:05:41
 @@ -709,12 +709,10 @@
  		callout_reset(&(sc->sc_tmo_intrlist),
  		    (hz), (ehci_intrlist_timeout), (sc));

 -#ifdef USB_USE_SOFTINTR
  	if (sc->sc_softwake) {
  		sc->sc_softwake = 0;
  		wakeup(&sc->sc_softwake);
  	}
 -#endif /* USB_USE_SOFTINTR */

  	sc->sc_bus.intr_context--;
  }
 @@ -763,7 +761,11 @@
  	    lsqtd->offs + offsetof(ehci_qtd_t, qtd_status),
  	    sizeof(lsqtd->qtd.qtd_status),
  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (le32toh(lsqtd->qtd.qtd_status) & EHCI_QTD_ACTIVE) {
 +	status = le32toh(lsqtd->qtd.qtd_status);
 +	usb_syncmem(&lsqtd->dma,
 +	    lsqtd->offs + offsetof(ehci_qtd_t, qtd_status),
 +	    sizeof(lsqtd->qtd.qtd_status), BUS_DMASYNC_PREREAD);
 +	if (status & EHCI_QTD_ACTIVE) {
  		DPRINTFN(12, ("ehci_check_intr: active ex=%p\n", ex));
  		for (sqtd = ex->sqtdstart; sqtd != lsqtd; sqtd=sqtd->nextqtd) {
  			usb_syncmem(&sqtd->dma,
 @@ -786,9 +788,6 @@
  		}
  		DPRINTFN(12, ("ehci_check_intr: ex=%p std=%p still active\n",
  			      ex, ex->sqtdstart));
 -		usb_syncmem(&lsqtd->dma,
 -		    lsqtd->offs + offsetof(ehci_qtd_t, qtd_status),
 -		    sizeof(lsqtd->qtd.qtd_status), BUS_DMASYNC_PREREAD);
  		return;
  	}
   done:
 @@ -1730,8 +1729,6 @@
  Static void
  ehci_add_qh(ehci_soft_qh_t *sqh, ehci_soft_qh_t *head)
  {
 -	SPLUSBCHECK;
 -
  	usb_syncmem(&head->dma, head->offs + offsetof(ehci_qh_t, qh_link),
  	    sizeof(head->qh.qh_link), BUS_DMASYNC_POSTWRITE);
  	sqh->next = head->next;
 @@ -1759,7 +1756,6 @@
  {
  	ehci_soft_qh_t *p;

 -	SPLUSBCHECK;
  	/* XXX */
  	for (p = head; p != NULL && p->next != sqh; p = p->next)
  		;
 @@ -2723,14 +2719,14 @@
  			ehci_physaddr_t a = dataphys + i * EHCI_PAGE_SIZE;
  			if (i != 0) /* use offset only in first buffer */
  				a = EHCI_PAGE(a);
 -			cur->qtd.qtd_buffer[i] = htole32(a);
 -			cur->qtd.qtd_buffer_hi[i] = 0;
 -#ifdef DIAGNOSTIC
  			if (i >= EHCI_QTD_NBUFFERS) {
 +#ifdef DIAGNOSTIC
  				printf("ehci_alloc_sqtd_chain: i=%d\n", i);
 +#endif
  				goto nomem;
  			}
 -#endif
 +			cur->qtd.qtd_buffer[i] = htole32(a);
 +			cur->qtd.qtd_buffer_hi[i] = 0;
  		}
  		cur->nextqtd = next;
  		cur->qtd.qtd_next = cur->qtd.qtd_altnext = nextphys;
 @@ -2982,13 +2978,9 @@
  	 */
  	ehci_sync_hc(sc);
  	s = splusb();
 -#ifdef USB_USE_SOFTINTR
  	sc->sc_softwake = 1;
 -#endif /* USB_USE_SOFTINTR */
  	usb_schedsoftintr(&sc->sc_bus);
 -#ifdef USB_USE_SOFTINTR
  	tsleep(&sc->sc_softwake, PZERO, "ehciab", 0);
 -#endif /* USB_USE_SOFTINTR */
  	splx(s);

  	/*
 @@ -3111,13 +3103,9 @@
  	splx(s);

          s = splusb();
 -#ifdef USB_USE_SOFTINTR
          sc->sc_softwake = 1;
 -#endif /* USB_USE_SOFTINTR */
          usb_schedsoftintr(&sc->sc_bus);
 -#ifdef USB_USE_SOFTINTR
          tsleep(&sc->sc_softwake, PZERO, "ehciab", 0);
 -#endif /* USB_USE_SOFTINTR */
          splx(s);

  #ifdef DIAGNOSTIC

 --------------010806070309050602060802
 Content-Type: text/plain;
  name="uhci.c-diff"
 Content-Transfer-Encoding: 7bit
 Content-Disposition: inline;
  filename="uhci.c-diff"

 --- uhci.c	2013/09/25 07:38:39	1.1
 +++ uhci.c	2013/09/25 08:07:25
 @@ -1076,8 +1076,6 @@
  {
  	uhci_soft_qh_t *eqh;

 -	SPLUSBCHECK;
 -
  	DPRINTFN(10, ("uhci_add_ctrl: sqh=%p\n", sqh));
  	eqh = sc->sc_hctl_end;
  	usb_syncmem(&eqh->dma, eqh->offs + offsetof(uhci_qh_t, qh_hlink),
 @@ -1103,8 +1101,6 @@
  {
  	uhci_soft_qh_t *pqh;

 -	SPLUSBCHECK;
 -
  	DPRINTFN(10, ("uhci_remove_hs_ctrl: sqh=%p\n", sqh));
  #ifdef UHCI_CTL_LOOP
  	uhci_rem_loop(sc);
 @@ -1153,8 +1149,6 @@
  {
  	uhci_soft_qh_t *eqh;

 -	SPLUSBCHECK;
 -
  	DPRINTFN(10, ("uhci_add_ls_ctrl: sqh=%p\n", sqh));
  	eqh = sc->sc_lctl_end;
  	usb_syncmem(&eqh->dma, eqh->offs + offsetof(uhci_qh_t, qh_hlink),
 @@ -1175,15 +1169,17 @@
  uhci_remove_ls_ctrl(uhci_softc_t *sc, uhci_soft_qh_t *sqh)
  {
  	uhci_soft_qh_t *pqh;
 -
 -	SPLUSBCHECK;
 +	uint32_t elink;

  	DPRINTFN(10, ("uhci_remove_ls_ctrl: sqh=%p\n", sqh));
  	/* See comment in uhci_remove_hs_ctrl() */
  	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
  	    sizeof(sqh->qh.qh_elink),
  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (!(sqh->qh.qh_elink & htole32(UHCI_PTR_T))) {
 +	elink = le32toh(sqh->qh.qh_elink);
 +	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 +	    sizeof(sqh->qh.qh_elink), BUS_DMASYNC_PREREAD);
 +	if (!(elink & UHCI_PTR_T)) {
  		sqh->qh.qh_elink = htole32(UHCI_PTR_T);
  		usb_syncmem(&sqh->dma,
  		    sqh->offs + offsetof(uhci_qh_t, qh_elink),
 @@ -1210,8 +1206,6 @@
  {
  	uhci_soft_qh_t *eqh;

 -	SPLUSBCHECK;
 -
  	DPRINTFN(10, ("uhci_add_bulk: sqh=%p\n", sqh));
  	eqh = sc->sc_bulk_end;
  	usb_syncmem(&eqh->dma, eqh->offs + offsetof(uhci_qh_t, qh_hlink),
 @@ -1234,8 +1228,6 @@
  {
  	uhci_soft_qh_t *pqh;

 -	SPLUSBCHECK;
 -
  	DPRINTFN(10, ("uhci_remove_bulk: sqh=%p\n", sqh));
  	uhci_rem_loop(sc);
  	/* See comment in uhci_remove_hs_ctrl() */
 @@ -1382,12 +1374,10 @@
  		uhci_check_intr(sc, ii);
  	}

 -#ifdef USB_USE_SOFTINTR
  	if (sc->sc_softwake) {
  		sc->sc_softwake = 0;
  		wakeup(&sc->sc_softwake);
  	}
 -#endif /* USB_USE_SOFTINTR */

  	sc->sc_bus.intr_context--;
  }
 @@ -1430,7 +1420,12 @@
  	    lstd->offs + offsetof(uhci_td_t, td_status),
  	    sizeof(lstd->td.td_status),
  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (le32toh(lstd->td.td_status) & UHCI_TD_ACTIVE) {
 +	status = le32toh(lstd->td.td_status);
 +	usb_syncmem(&lstd->dma,
 +	    lstd->offs + offsetof(uhci_td_t, td_status),
 +	    sizeof(lstd->td.td_status),
 +	    BUS_DMASYNC_PREREAD);
 +	if (status & UHCI_TD_ACTIVE) {
  		DPRINTFN(12, ("uhci_check_intr: active ii=%p\n", ii));
  		for (std = ii->stdstart; std != lstd; std = std->link.std) {
  			usb_syncmem(&std->dma,
 @@ -1459,10 +1454,6 @@
  		}
  		DPRINTFN(12, ("uhci_check_intr: ii=%p std=%p still active\n",
  			      ii, ii->stdstart));
 -		usb_syncmem(&lstd->dma,
 -		    lstd->offs + offsetof(uhci_td_t, td_status),
 -		    sizeof(lstd->td.td_status),
 -		    BUS_DMASYNC_PREREAD);
  		return;
  	}
   done:
 @@ -1830,6 +1821,7 @@
  		    uhci_soft_td_t *stdend)
  {
  	uhci_soft_td_t *p;
 +	uint32_t td_link;

  	/*
  	 * to avoid race condition with the controller which may be looking
 @@ -1841,8 +1833,13 @@
  		    p->offs + offsetof(uhci_td_t, td_link),
  		    sizeof(p->td.td_link),
  		    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -		if ((p->td.td_link & UHCI_PTR_T) == 0) {
 -			p->td.td_link = UHCI_PTR_T;
 +		td_link =  le32toh(p->td.td_link);
 +		usb_syncmem(&p->dma,
 +		    p->offs + offsetof(uhci_td_t, td_link),
 +		    sizeof(p->td.td_link),
 +		    BUS_DMASYNC_PREREAD);
 +		if ((td_link & UHCI_PTR_T) == 0) {
 +			p->td.td_link = htole32(UHCI_PTR_T);
  			usb_syncmem(&p->dma,
  			    p->offs + offsetof(uhci_td_t, td_link),
  			    sizeof(p->td.td_link),
 @@ -2142,14 +2139,10 @@
  	 */
  	usb_delay_ms(upipe->pipe.device->bus, 2); /* Hardware finishes in 1ms */
  	s = splusb();
 -#ifdef USB_USE_SOFTINTR
  	sc->sc_softwake = 1;
 -#endif /* USB_USE_SOFTINTR */
  	usb_schedsoftintr(&sc->sc_bus);
 -#ifdef USB_USE_SOFTINTR
  	DPRINTFN(1,("uhci_abort_xfer: tsleep\n"));
  	tsleep(&sc->sc_softwake, PZERO, "uhciab", 0);
 -#endif /* USB_USE_SOFTINTR */
  	splx(s);

  	/*

 --------------010806070309050602060802--

From: Nick Hudson <skrll@netbsd.org>
To: Wolfgang Stukenbrock <wolfgang.stukenbrock@nagler-company.com>
Cc: gnats-bugs@NetBSD.org, kern-bug-people@NetBSD.org, 
 gnats-admin@NetBSD.org, netbsd-bugs@NetBSD.org
Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device
 (umodem)
Date: Wed, 25 Sep 2013 10:15:22 +0100

 This is a multi-part message in MIME format.
 --------------030401000304070401080704
 Content-Type: text/plain; charset=ISO-8859-1; format=flowed
 Content-Transfer-Encoding: 7bit

 On 09/25/13 10:01, Wolfgang Stukenbrock wrote:
 > Hi,
 >
 hi,

 > My base version is the 1.212 for uhci.c from the release tree.

 Did you mean 1.242 which is the netbsd-6 version?

 http://cvsweb.netbsd.org/bsdweb.cgi/src/sys/dev/usb/uhci.c?only_with_tag=netbsd-6

 Here's a diff against this version of uhci.c which will fix your 
 problem, I think.

 Nick

 --------------030401000304070401080704
 Content-Type: text/plain; charset=us-ascii;
  name="uhci.c.diff"
 Content-Transfer-Encoding: 7bit
 Content-Disposition: attachment;
  filename="uhci.c.diff"

 Index: sys/dev/usb/uhci.c
 ===================================================================
 RCS file: /cvsroot/src/sys/dev/usb/uhci.c,v
 retrieving revision 1.242
 diff -u -p -r1.242 uhci.c
 --- sys/dev/usb/uhci.c	23 Dec 2011 00:51:46 -0000	1.242
 +++ sys/dev/usb/uhci.c	25 Sep 2013 09:09:56 -0000
 @@ -1102,6 +1102,7 @@ void
  uhci_remove_hs_ctrl(uhci_softc_t *sc, uhci_soft_qh_t *sqh)
  {
  	uhci_soft_qh_t *pqh;
 +	uint32_t elink;

  	SPLUSBCHECK;

 @@ -1125,7 +1126,10 @@ uhci_remove_hs_ctrl(uhci_softc_t *sc, uh
  	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
  	    sizeof(sqh->qh.qh_elink),
  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (!(sqh->qh.qh_elink & htole32(UHCI_PTR_T))) {
 +	elink = le32toh(sqh->qh.qh_elink);
 +	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 +	    sizeof(sqh->qh.qh_elink), BUS_DMASYNC_PREREAD);
 +	if (!(elink & UHCI_PTR_T)) {
  		sqh->qh.qh_elink = htole32(UHCI_PTR_T);
  		usb_syncmem(&sqh->dma,
  		    sqh->offs + offsetof(uhci_qh_t, qh_elink),
 @@ -1175,6 +1179,7 @@ void
  uhci_remove_ls_ctrl(uhci_softc_t *sc, uhci_soft_qh_t *sqh)
  {
  	uhci_soft_qh_t *pqh;
 +	uint32_t elink;

  	SPLUSBCHECK;

 @@ -1183,7 +1188,10 @@ uhci_remove_ls_ctrl(uhci_softc_t *sc, uh
  	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
  	    sizeof(sqh->qh.qh_elink),
  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (!(sqh->qh.qh_elink & htole32(UHCI_PTR_T))) {
 +	elink = le32toh(sqh->qh.qh_elink);
 +	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 +	    sizeof(sqh->qh.qh_elink), BUS_DMASYNC_PREREAD);
 +	if (!(elink & UHCI_PTR_T)) {
  		sqh->qh.qh_elink = htole32(UHCI_PTR_T);
  		usb_syncmem(&sqh->dma,
  		    sqh->offs + offsetof(uhci_qh_t, qh_elink),
 @@ -1421,54 +1429,89 @@ uhci_check_intr(uhci_softc_t *sc, uhci_i
  		return;
  	}
  #endif
 +	usb_syncmem(&lstd->dma,
 +	    lstd->offs + offsetof(uhci_td_t, td_status),
 +	    sizeof(lstd->td.td_status),
 +	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 +	status = le32toh(lstd->td.td_status);
 +	usb_syncmem(&lstd->dma,
 +	    lstd->offs + offsetof(uhci_td_t, td_status),
 +	    sizeof(lstd->td.td_status),
 +	    BUS_DMASYNC_PREREAD);
 +
 +	/* If the last TD is not marked active we can complete */
 +	if (!(status & UHCI_TD_ACTIVE)) {
 + done:
 +		DPRINTFN(12, ("uhci_check_intr: ii=%p done\n", ii));
 +		callout_stop(&ii->xfer->timeout_handle);
 +		uhci_idone(ii);
 + 		return;
 + 	}
 +
  	/*
  	 * If the last TD is still active we need to check whether there
  	 * is an error somewhere in the middle, or whether there was a
  	 * short packet (SPD and not ACTIVE).
  	 */
 -	usb_syncmem(&lstd->dma,
 -	    lstd->offs + offsetof(uhci_td_t, td_status),
 -	    sizeof(lstd->td.td_status),
 -	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -	if (le32toh(lstd->td.td_status) & UHCI_TD_ACTIVE) {
 -		DPRINTFN(12, ("uhci_check_intr: active ii=%p\n", ii));
 -		for (std = ii->stdstart; std != lstd; std = std->link.std) {
 -			usb_syncmem(&std->dma,
 -			    std->offs + offsetof(uhci_td_t, td_status),
 -			    sizeof(std->td.td_status),
 -			    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 -			status = le32toh(std->td.td_status);
 -			usb_syncmem(&std->dma,
 -			    std->offs + offsetof(uhci_td_t, td_status),
 -			    sizeof(std->td.td_status), BUS_DMASYNC_PREREAD);
 -			/* If there's an active TD the xfer isn't done. */
 -			if (status & UHCI_TD_ACTIVE)
 -				break;
 -			/* Any kind of error makes the xfer done. */
 -			if (status & UHCI_TD_STALLED)
 -				goto done;
 -			/* We want short packets, and it is short: it's done */
 -			usb_syncmem(&std->dma,
 -			    std->offs + offsetof(uhci_td_t, td_token),
 -			    sizeof(std->td.td_token),
 -			    BUS_DMASYNC_POSTWRITE);
 -			if ((status & UHCI_TD_SPD) &&
 -			      UHCI_TD_GET_ACTLEN(status) <
 -			      UHCI_TD_GET_MAXLEN(le32toh(std->td.td_token)))
 -				goto done;
 -		}
 -		DPRINTFN(12, ("uhci_check_intr: ii=%p std=%p still active\n",
 -			      ii, ii->stdstart));
 -		usb_syncmem(&lstd->dma,
 -		    lstd->offs + offsetof(uhci_td_t, td_status),
 -		    sizeof(lstd->td.td_status),
 -		    BUS_DMASYNC_PREREAD);
 -		return;
 +	DPRINTFN(12, ("uhci_check_intr: active ii=%p\n", ii));
 +	for (std = ii->stdstart; std != lstd; std = std->link.std) {
 +		usb_syncmem(&std->dma,
 +		    std->offs + offsetof(uhci_td_t, td_status),
 +		    sizeof(std->td.td_status),
 +		    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 +		status = le32toh(std->td.td_status);
 +		usb_syncmem(&std->dma,
 +		    std->offs + offsetof(uhci_td_t, td_status),
 +		    sizeof(std->td.td_status), BUS_DMASYNC_PREREAD);
 +
 +		/* If there's an active TD the xfer isn't done. */
 +		if (status & UHCI_TD_ACTIVE) {
 +			DPRINTFN(12, ("%s: ii=%p std=%p still active\n",
 +			    __func__, ii, std));
 +			return;
 +		}
 +
 +		/* Any kind of error makes the xfer done. */
 +		if (status & UHCI_TD_STALLED)
 +			goto done;
 +
 +		/*
 +		 * If the data phase of a control transfer is short, we need
 +		 * to complete the status stage
 +		 */
 +		usbd_xfer_handle xfer = ii->xfer;
 +		usb_endpoint_descriptor_t *ed = xfer->pipe->endpoint->edesc;
 +		uint8_t xfertype = UE_GET_XFERTYPE(ed->bmAttributes);
 +
 +		if ((status & UHCI_TD_SPD) && xfertype == UE_CONTROL) {
 +			struct uhci_pipe *upipe =
 +			    (struct uhci_pipe *)xfer->pipe;
 +			uhci_soft_qh_t *sqh = upipe->u.ctl.sqh;
 +			uhci_soft_td_t *stat = upipe->u.ctl.stat;
 +
 +			DPRINTFN(12, ("%s: ii=%p std=%p control status"
 +			    "phase needs completion\n", __func__, ii,
 +			    ii->stdstart));
 +
 +			sqh->qh.qh_elink =
 +			    htole32(stat->physaddr | UHCI_PTR_TD);
 +			usb_syncmem(&sqh->dma, sqh->offs, sizeof(sqh->qh),
 +			    BUS_DMASYNC_PREWRITE);
 +			break;
 +		}
 +
 +		/* We want short packets, and it is short: it's done */
 +		usb_syncmem(&std->dma,
 +		    std->offs + offsetof(uhci_td_t, td_token),
 +		    sizeof(std->td.td_token),
 +		    BUS_DMASYNC_POSTWRITE);
 +
 +		if ((status & UHCI_TD_SPD) &&
 +			UHCI_TD_GET_ACTLEN(status) <
 +			UHCI_TD_GET_MAXLEN(le32toh(std->td.td_token))) {
 +			goto done;
 +		}
  	}
 - done:
 -	DPRINTFN(12, ("uhci_check_intr: ii=%p done\n", ii));
 -	callout_stop(&ii->xfer->timeout_handle);
 -	uhci_idone(ii);
  }

  /* Called at splusb() */
 @@ -2420,7 +2463,7 @@ uhci_device_request(usbd_xfer_handle xfe
  			return (err);
  		next = data;
  		dataend->link.std = stat;
 -		dataend->td.td_link = htole32(stat->physaddr | UHCI_PTR_VF | UHCI_PTR_TD);
 +		dataend->td.td_link = htole32(stat->physaddr | UHCI_PTR_TD);
  		usb_syncmem(&dataend->dma,
  		    dataend->offs + offsetof(uhci_td_t, td_link),
  		    sizeof(dataend->td.td_link),
 @@ -2434,7 +2477,7 @@ uhci_device_request(usbd_xfer_handle xfe
  	usb_syncmem(&upipe->u.ctl.reqdma, 0, sizeof *req, BUS_DMASYNC_PREWRITE);

  	setup->link.std = next;
 -	setup->td.td_link = htole32(next->physaddr | UHCI_PTR_VF | UHCI_PTR_TD);
 +	setup->td.td_link = htole32(next->physaddr | UHCI_PTR_TD);
  	setup->td.td_status = htole32(UHCI_TD_SET_ERRCNT(3) | ls |
  		UHCI_TD_ACTIVE);
  	setup->td.td_token = htole32(UHCI_TD_SETUP(sizeof *req, endpt, addr));


 --------------030401000304070401080704--

From: Wolfgang Stukenbrock <wolfgang.stukenbrock@nagler-company.com>
To: Nick Hudson <skrll@netbsd.org>
Cc: gnats-bugs@netbsd.org, kern-bug-people@netbsd.org, gnats-admin@netbsd.org,
        netbsd-bugs@netbsd.org
Subject: Re: kern/48237: NetBSD 6.1 failed to detect USB 1.x full-speed device (umodem)
Date: Wed, 25 Sep 2013 14:53:08 +0200

 Hi again,

 I've added the patch and the USB modems comes up again.

 Thanks for the patch.
 It should go into the the 6.x tree as soon as possible ....



 Neverless, during reboot I've still "some" incomplete USB-transactions.
 I'm not 100% shure what excatly is gooing on, but it must be related to 
 the forced shutdown of my "getty-Version" on the com-line by init.
 The process tries to open /dev/ttyU0 and waits for carrier when it is 
 killed by a signal.
 This will also happen if I kill the process by hand.

 remark:
 I've a patch for umodem/ucom in the kernel to catch RI (and reset it 
 after some time) in order to raise DCD to allow ucom-driver to finish 
 the pending open(). This patch is present in all of my kernels because 
 without it umodem (and my hardware) cannot be used for dialin/dialout lines.
 On real serial lines, I can patch the cable, but this impossible for 
 USB-modems that does not support raising DCD on incoming calls.
 I'm not shure if I ever reported this (in 2.0.2 or later), because after 
 some discution at that time, it looks like it would never come into any 
 release. I cannot find it in the Gnats-DB at the moment and also not in 
 my mail archive.
 If you think I should start an other try for this topic, let me know.



 The not terminating transfer seems to be a bulk-transfer this time after 
 one other communication step. Here my debug-printout during system 
 shutdown, just before syncing the disks.


 uhci_idone: ii=0xc1f51a40
 uhci_idone: ii=0xc1f51a40, xfer=0xc1f519c4, pipe=0xc1725a9c ready
   ---- loop start ....
   ---- status 0x18000007 act-len 0 token 0xe0022d
   ---- status 0x190007ff act-len 0 token 0xffe80269
   ---- adding len -> act-len 0
 uhci_idone: actlen=0, status=0x0
 uhci_idone: ii=0xc1f51b20
 uhci_idone: ii=0xc1f51b20, xfer=0xc1f51aa4, pipe=0xc172586c ready
   ---- loop start ....
   ---- status 0x18000007 act-len 0 token 0xe0032d
   ---- status 0x190007ff act-len 0 token 0xffe80369
   ---- adding len -> act-len 0
 uhci_idone: actlen=0, status=0x0
 uhci_idone: ii=0xc1f51f80
 uhci_idone: ii=0xc1f51f80, xfer=0xc1f51f04, pipe=0xc172516c ready
   ---- loop start ....
   ---- status 0x38000005 act-len 0 token 0x7e30269
   ---- adding len -> act-len 6
   ---- ACTIVE TD found ....
 uhci_idone: actlen=6, status=0x0
 uhci_idone: ii=0xc1f51ea0
 uhci_idone: ii=0xc1f51ea0, xfer=0xc1f51e24, pipe=0xc172524c ready
   ---- loop start ....
   ---- status 0x38000005 act-len 0 token 0x7e30369
   ---- adding len -> act-len 6
   ---- ACTIVE TD found ....
 uhci_idone: actlen=6, status=0x0
 uhci_device_bulk_abort:
 uhci_device_bulk_abort:
 uhci_check_intr: aborted xfer=0xc1f51e24
 uhci_check_intr: aborted xfer=0xc1f51f04
 uhci_check_intr: aborted xfer=0xc1f51e24


 remark: there are two modems active on the systems, one pending bulk 
 transfer for each ...


 I haven't tested "real" data till now. Next step on my side is to 
 integrate the patch in our NetBSD-installation-base and reinstall the 
 system to get all manualy added debug-stuff eliminated.

 best regards

 W. Stukenbrock


 Nick Hudson wrote:

 > On 09/25/13 10:01, Wolfgang Stukenbrock wrote:
 > 
 >> Hi,
 >>
 > hi,
 > 
 >> My base version is the 1.212 for uhci.c from the release tree.
 > 
 > 
 > Did you mean 1.242 which is the netbsd-6 version?
 > 
 > http://cvsweb.netbsd.org/bsdweb.cgi/src/sys/dev/usb/uhci.c?only_with_tag=netbsd-6 
 > 
 > 
 > Here's a diff against this version of uhci.c which will fix your 
 > problem, I think.
 > 
 > Nick
 > 
 > 
 > ------------------------------------------------------------------------
 > 
 > Index: sys/dev/usb/uhci.c
 > ===================================================================
 > RCS file: /cvsroot/src/sys/dev/usb/uhci.c,v
 > retrieving revision 1.242
 > diff -u -p -r1.242 uhci.c
 > --- sys/dev/usb/uhci.c	23 Dec 2011 00:51:46 -0000	1.242
 > +++ sys/dev/usb/uhci.c	25 Sep 2013 09:09:56 -0000
 > @@ -1102,6 +1102,7 @@ void
 >  uhci_remove_hs_ctrl(uhci_softc_t *sc, uhci_soft_qh_t *sqh)
 >  {
 >  	uhci_soft_qh_t *pqh;
 > +	uint32_t elink;
 >  
 >  	SPLUSBCHECK;
 >  
 > @@ -1125,7 +1126,10 @@ uhci_remove_hs_ctrl(uhci_softc_t *sc, uh
 >  	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 >  	    sizeof(sqh->qh.qh_elink),
 >  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > -	if (!(sqh->qh.qh_elink & htole32(UHCI_PTR_T))) {
 > +	elink = le32toh(sqh->qh.qh_elink);
 > +	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 > +	    sizeof(sqh->qh.qh_elink), BUS_DMASYNC_PREREAD);
 > +	if (!(elink & UHCI_PTR_T)) {
 >  		sqh->qh.qh_elink = htole32(UHCI_PTR_T);
 >  		usb_syncmem(&sqh->dma,
 >  		    sqh->offs + offsetof(uhci_qh_t, qh_elink),
 > @@ -1175,6 +1179,7 @@ void
 >  uhci_remove_ls_ctrl(uhci_softc_t *sc, uhci_soft_qh_t *sqh)
 >  {
 >  	uhci_soft_qh_t *pqh;
 > +	uint32_t elink;
 >  
 >  	SPLUSBCHECK;
 >  
 > @@ -1183,7 +1188,10 @@ uhci_remove_ls_ctrl(uhci_softc_t *sc, uh
 >  	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 >  	    sizeof(sqh->qh.qh_elink),
 >  	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > -	if (!(sqh->qh.qh_elink & htole32(UHCI_PTR_T))) {
 > +	elink = le32toh(sqh->qh.qh_elink);
 > +	usb_syncmem(&sqh->dma, sqh->offs + offsetof(uhci_qh_t, qh_elink),
 > +	    sizeof(sqh->qh.qh_elink), BUS_DMASYNC_PREREAD);
 > +	if (!(elink & UHCI_PTR_T)) {
 >  		sqh->qh.qh_elink = htole32(UHCI_PTR_T);
 >  		usb_syncmem(&sqh->dma,
 >  		    sqh->offs + offsetof(uhci_qh_t, qh_elink),
 > @@ -1421,54 +1429,89 @@ uhci_check_intr(uhci_softc_t *sc, uhci_i
 >  		return;
 >  	}
 >  #endif
 > +	usb_syncmem(&lstd->dma,
 > +	    lstd->offs + offsetof(uhci_td_t, td_status),
 > +	    sizeof(lstd->td.td_status),
 > +	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > +	status = le32toh(lstd->td.td_status);
 > +	usb_syncmem(&lstd->dma,
 > +	    lstd->offs + offsetof(uhci_td_t, td_status),
 > +	    sizeof(lstd->td.td_status),
 > +	    BUS_DMASYNC_PREREAD);
 > +
 > +	/* If the last TD is not marked active we can complete */
 > +	if (!(status & UHCI_TD_ACTIVE)) {
 > + done:
 > +		DPRINTFN(12, ("uhci_check_intr: ii=%p done\n", ii));
 > +		callout_stop(&ii->xfer->timeout_handle);
 > +		uhci_idone(ii);
 > + 		return;
 > + 	}
 > +
 >  	/*
 >  	 * If the last TD is still active we need to check whether there
 >  	 * is an error somewhere in the middle, or whether there was a
 >  	 * short packet (SPD and not ACTIVE).
 >  	 */
 > -	usb_syncmem(&lstd->dma,
 > -	    lstd->offs + offsetof(uhci_td_t, td_status),
 > -	    sizeof(lstd->td.td_status),
 > -	    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > -	if (le32toh(lstd->td.td_status) & UHCI_TD_ACTIVE) {
 > -		DPRINTFN(12, ("uhci_check_intr: active ii=%p\n", ii));
 > -		for (std = ii->stdstart; std != lstd; std = std->link.std) {
 > -			usb_syncmem(&std->dma,
 > -			    std->offs + offsetof(uhci_td_t, td_status),
 > -			    sizeof(std->td.td_status),
 > -			    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > -			status = le32toh(std->td.td_status);
 > -			usb_syncmem(&std->dma,
 > -			    std->offs + offsetof(uhci_td_t, td_status),
 > -			    sizeof(std->td.td_status), BUS_DMASYNC_PREREAD);
 > -			/* If there's an active TD the xfer isn't done. */
 > -			if (status & UHCI_TD_ACTIVE)
 > -				break;
 > -			/* Any kind of error makes the xfer done. */
 > -			if (status & UHCI_TD_STALLED)
 > -				goto done;
 > -			/* We want short packets, and it is short: it's done */
 > -			usb_syncmem(&std->dma,
 > -			    std->offs + offsetof(uhci_td_t, td_token),
 > -			    sizeof(std->td.td_token),
 > -			    BUS_DMASYNC_POSTWRITE);
 > -			if ((status & UHCI_TD_SPD) &&
 > -			      UHCI_TD_GET_ACTLEN(status) <
 > -			      UHCI_TD_GET_MAXLEN(le32toh(std->td.td_token)))
 > -				goto done;
 > -		}
 > -		DPRINTFN(12, ("uhci_check_intr: ii=%p std=%p still active\n",
 > -			      ii, ii->stdstart));
 > -		usb_syncmem(&lstd->dma,
 > -		    lstd->offs + offsetof(uhci_td_t, td_status),
 > -		    sizeof(lstd->td.td_status),
 > -		    BUS_DMASYNC_PREREAD);
 > -		return;
 > +	DPRINTFN(12, ("uhci_check_intr: active ii=%p\n", ii));
 > +	for (std = ii->stdstart; std != lstd; std = std->link.std) {
 > +		usb_syncmem(&std->dma,
 > +		    std->offs + offsetof(uhci_td_t, td_status),
 > +		    sizeof(std->td.td_status),
 > +		    BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
 > +		status = le32toh(std->td.td_status);
 > +		usb_syncmem(&std->dma,
 > +		    std->offs + offsetof(uhci_td_t, td_status),
 > +		    sizeof(std->td.td_status), BUS_DMASYNC_PREREAD);
 > +
 > +		/* If there's an active TD the xfer isn't done. */
 > +		if (status & UHCI_TD_ACTIVE) {
 > +			DPRINTFN(12, ("%s: ii=%p std=%p still active\n",
 > +			    __func__, ii, std));
 > +			return;
 > +		}
 > +
 > +		/* Any kind of error makes the xfer done. */
 > +		if (status & UHCI_TD_STALLED)
 > +			goto done;
 > +
 > +		/*
 > +		 * If the data phase of a control transfer is short, we need
 > +		 * to complete the status stage
 > +		 */
 > +		usbd_xfer_handle xfer = ii->xfer;
 > +		usb_endpoint_descriptor_t *ed = xfer->pipe->endpoint->edesc;
 > +		uint8_t xfertype = UE_GET_XFERTYPE(ed->bmAttributes);
 > +
 > +		if ((status & UHCI_TD_SPD) && xfertype == UE_CONTROL) {
 > +			struct uhci_pipe *upipe =
 > +			    (struct uhci_pipe *)xfer->pipe;
 > +			uhci_soft_qh_t *sqh = upipe->u.ctl.sqh;
 > +			uhci_soft_td_t *stat = upipe->u.ctl.stat;
 > +
 > +			DPRINTFN(12, ("%s: ii=%p std=%p control status"
 > +			    "phase needs completion\n", __func__, ii,
 > +			    ii->stdstart));
 > +
 > +			sqh->qh.qh_elink =
 > +			    htole32(stat->physaddr | UHCI_PTR_TD);
 > +			usb_syncmem(&sqh->dma, sqh->offs, sizeof(sqh->qh),
 > +			    BUS_DMASYNC_PREWRITE);
 > +			break;
 > +		}
 > +
 > +		/* We want short packets, and it is short: it's done */
 > +		usb_syncmem(&std->dma,
 > +		    std->offs + offsetof(uhci_td_t, td_token),
 > +		    sizeof(std->td.td_token),
 > +		    BUS_DMASYNC_POSTWRITE);
 > +
 > +		if ((status & UHCI_TD_SPD) &&
 > +			UHCI_TD_GET_ACTLEN(status) <
 > +			UHCI_TD_GET_MAXLEN(le32toh(std->td.td_token))) {
 > +			goto done;
 > +		}
 >  	}
 > - done:
 > -	DPRINTFN(12, ("uhci_check_intr: ii=%p done\n", ii));
 > -	callout_stop(&ii->xfer->timeout_handle);
 > -	uhci_idone(ii);
 >  }
 >  
 >  /* Called at splusb() */
 > @@ -2420,7 +2463,7 @@ uhci_device_request(usbd_xfer_handle xfe
 >  			return (err);
 >  		next = data;
 >  		dataend->link.std = stat;
 > -		dataend->td.td_link = htole32(stat->physaddr | UHCI_PTR_VF | UHCI_PTR_TD);
 > +		dataend->td.td_link = htole32(stat->physaddr | UHCI_PTR_TD);
 >  		usb_syncmem(&dataend->dma,
 >  		    dataend->offs + offsetof(uhci_td_t, td_link),
 >  		    sizeof(dataend->td.td_link),
 > @@ -2434,7 +2477,7 @@ uhci_device_request(usbd_xfer_handle xfe
 >  	usb_syncmem(&upipe->u.ctl.reqdma, 0, sizeof *req, BUS_DMASYNC_PREWRITE);
 >  
 >  	setup->link.std = next;
 > -	setup->td.td_link = htole32(next->physaddr | UHCI_PTR_VF | UHCI_PTR_TD);
 > +	setup->td.td_link = htole32(next->physaddr | UHCI_PTR_TD);
 >  	setup->td.td_status = htole32(UHCI_TD_SET_ERRCNT(3) | ls |
 >  		UHCI_TD_ACTIVE);
 >  	setup->td.td_token = htole32(UHCI_TD_SETUP(sizeof *req, endpt, addr));
 > 
 > 


 -- 


 Dr. Nagler & Company GmbH
 Hauptstraße 9
 92253 Schnaittenbach

 Tel. +49 9622/71 97-42
 Fax +49 9622/71 97-50

 Wolfgang.Stukenbrock@nagler-company.com
 http://www.nagler-company.com


 Hauptsitz: Schnaittenbach
 Handelregister: Amberg HRB
 Gerichtsstand: Amberg
 Steuernummer: 201/118/51825
 USt.-ID-Nummer: DE 273143997
 Geschäftsführer: Dr. Martin Nagler, Prof. Dr. Dr. Karl-Kuno Kunze


State-Changed-From-To: open->closed
State-Changed-By: mrg@NetBSD.org
State-Changed-When: Fri, 23 Aug 2019 07:13:29 +0000
State-Changed-Why:
skrll merged fixes for this some time ago.  thanks!


>Unformatted:

NetBSD Home
NetBSD PR Database Search

(Contact us) $NetBSD: query-full-pr,v 1.43 2018/01/16 07:36:43 maya Exp $
$NetBSD: gnats_config.sh,v 1.9 2014/08/02 14:16:04 spz Exp $
Copyright © 1994-2017 The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.