NetBSD-Bugs archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
Re: port-arm/60021: USB-only boot: uhub0 attaches but uhub1 never appears, no hotplug events; SD-boot sees hub+umass fine
The following reply was made to PR port-arm/60021; it has been noted by GNATS.
From: Michael Cheponis <michael.cheponis%gmail.com@localhost>
To: gnats-bugs%netbsd.org@localhost
Cc: port-arm-maintainer%netbsd.org@localhost, gnats-admin%netbsd.org@localhost,
netbsd-bugs%netbsd.org@localhost, mac%culver.net@localhost
Subject: Re: port-arm/60021: USB-only boot: uhub0 attaches but uhub1 never
appears, no hotplug events; SD-boot sees hub+umass fine
Date: Wed, 5 Aug 2026 19:55:22 -0700
--0000000000001c50be0658580742
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Here is the output with usb debug:
RPi3B+ USB boot diagnostic kernel
Wed Aug 5 20:44:41 UTC 2026
NetBSD SS.Culver.Net 11.0_RC5 NetBSD 11.0_RC5 (GENERIC) #0: Tue Jun 16
15:48:07 UTC 2026
mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/amd64/compile/GENERIC
amd64
Target: MACHINE=3Devbarm MACHINE_ARCH=3Daarch64
Source branch: netbsd-11
Kernel configuration: GENERIC64_USBDEBUG
Kernel hashes:
SHA256
(/root/obj-rpi3b-usbdebug/sys/arch/evbarm/compile/GENERIC64_USBDEBUG/netbsd=
)
=3D 96bdfcf491362c83a1eedd251c5de5bb44f9f8a565a351a6ee58e652cbfea91d
SHA256
(/root/obj-rpi3b-usbdebug/sys/arch/evbarm/compile/GENERIC64_USBDEBUG/netbsd=
.img)
=3D 6b0a14b4faf31249a9fd583c2e8ead68cf3fe4501484d9cb688992630a2f9773
Relevant CVS revisions:
File: usb.c Status: Up-to-date
Working revision: 1.203
Sticky Tag: netbsd-11 (branch: 1.203.4)
File: uhub.c Status: Up-to-date
Working revision: 1.162
Sticky Tag: netbsd-11 (branch: 1.162.4)
File: usb_subr.c Status: Up-to-date
Working revision: 1.279.4.1
Sticky Tag: netbsd-11 (branch: 1.279.4)
=E2=96=92[ 1.0000000] NetBSD/evbarm (fdt) booting ...
[ 1.0000000] Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003=
,
[ 1.0000000] 2004, 2005, 2006, 2007, 2008, 2009, 2010, 2011, 2012,
2013,
[ 1.0000000] 2014, 2015, 2016, 2017, 2018, 2019, 2020, 2021, 2022,
2023,
[ 1.0000000] 2024, 2025, 2026
[ 1.0000000] The NetBSD Foundation, Inc. All rights reserved.
[ 1.0000000] Copyright (c) 1982, 1986, 1989, 1991, 1993
[ 1.0000000] The Regents of the University of California. All rights
reserved.
[ 1.0000000] NetBSD 11.0_STABLE (GENERIC64_USBDEBUG) #0: Wed Aug 5
19:49:20 UTC 2026
[ 1.0000000] root%SS.Culver.Net@localhost:
/root/obj-rpi3b-usbdebug/sys/arch/evbarm/compile/GENERIC64_USBDEBUG
[ 1.0000000] total memory =3D 925 MB
[ 1.0000000] avail memory =3D 890 MB
[ 1.0000000] armfdt0 (root)
[ 1.0000000] simplebus0 at armfdt0: Raspberry Pi 3 Model B Plus Rev 1.4
[ 1.0000000] simplebus1 at simplebus0
[ 1.0000000] simplebus2 at simplebus0
[ 1.0000000] cpus0 at simplebus0
[ 1.0000000] simplebus3 at simplebus0
[ 1.0000000] cpu0 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0x0
[ 1.0000000] cpu0: package 0, core 0, smt 0, numa 0
[ 1.0000000] cpu1 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0x1
[ 1.0000000] cpu1: package 0, core 1, smt 0, numa 0
[ 1.0000000] cpu2 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0x2
[ 1.0000000] cpu2: package 0, core 2, smt 0, numa 0
[ 1.0000000] cpu3 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0x3
[ 1.0000000] cpu3: package 0, core 3, smt 0, numa 0
[ 1.0000000] bcmicu0 at simplebus1
[ 1.0000000] fclock0 at simplebus2: 19200000 Hz fixed clock (osc)
[ 1.0000000] bcmcprman0 at simplebus1: BCM283x Clock Controller
[ 1.0000000] syscon0 at simplebus1: couldn't get registers
[ 1.0000000] bcmaux0 at simplebus1
[ 1.0000000] fclock1 at simplebus2: 480000000 Hz fixed clock (otg)
[ 1.0000000] bcmicu1 at simplebus1: Multiprocessor
[ 1.0000000] gtmr0 at simplebus0: Generic Timer
[ 1.0000000] gtmr0: interrupting on local_intc irq 3
[ 1.0000000] armgtmr0 at gtmr0: Generic Timer (19200 kHz, virtual)
[ 1.0000040] bcmgpio0 at simplebus1: GPIO controller 2835
[ 1.0000040] bcmgpio0: pins 0..31 interrupting on icu irq 49
[ 1.0000040] bcmgpio0: pins 32..54 interrupting on icu irq 50
[ 1.0000040] gpio0 at bcmgpio0: 54 pins
[ 1.0000040] plcom0 at simplebus1: ARM PL011 UART
[ 1.0000040] plcom0: txfifo 16 bytes
[ 1.0000040] plcom0: interrupting on icu irq 57
[ 1.0000040] com0 at simplebus1: BCM AUX UART, 1-byte FIFO
[ 1.0000040] com0: console
[ 1.0000040] com0: interrupting on icu irq 29, clock 800000000 Hz
[ 1.0000040] mmcpwrseq0 at simplebus0: couldn't get reset GPIOs
[ 1.0000040] /soc/thermal@7e212000 at simplebus1 not configured
[ 1.0000040] bcmdmac0 at simplebus1: DMA0 DMA2 DMA4 DMA5 DMA6 DMA7 DMA8
DMA9 DMA10 DMA11
[ 1.0000040] /soc/power at simplebus1 not configured
[ 1.0000040] /phy at simplebus0 not configured
[ 1.0000040] bsciic0 at simplebus1: Broadcom Serial Controller
[ 1.0000040] bsciic0: interrupting on icu irq 53
[ 1.0000040] iic0 at bsciic0: I2C bus
[ 1.0000040] bcmmbox0 at simplebus1: VC mailbox
[ 1.0000040] bcmmbox0: interrupting on icu irq 65
[ 1.0000040] vcmbox0 at bcmmbox0
[ 1.0000040] /soc/timer@7e003000 at simplebus1 not configured
[ 1.0000040] /soc/txp@7e004000 at simplebus1 not configured
[ 1.0000040] bcmsdhost0 at simplebus1: SD HOST controller
[ 1.0000040] bcmsdhost0: interrupting on icu irq 56
[ 1.0000040] bsciic1 at simplebus1: Broadcom Serial Controller
[ 1.0000040] bsciic1: interrupting on icu irq 53
[ 1.0000040] iic1 at bsciic1: I2C bus
[ 1.0000040] /soc/pwm@7e20c000 at simplebus1 not configured
[ 1.0000040] sdhc0 at simplebus1: SDHC controller
[ 1.0000040] sdhc0: interrupting on icu irq 62
[ 1.0000040] bsciic2 at simplebus1: Broadcom Serial Controller
[ 1.0000040] bsciic2: interrupting on icu irq 53
[ 1.0000040] iic2 at bsciic2: I2C bus
[ 1.0000040] dwctwo0 at simplebus1: USB controller
[ 1.0000040] dwctwo0: interrupting on icu irq 9
[ 1.0000040] bcmpmwdog0 at simplebus1: Power management, Reset and
Watchdog controller
[ 1.0000040] /soc/vec@7e806000 at simplebus1 not configured
[ 1.0000040] /soc/hdmi@7e902000 at simplebus1 not configured
[ 1.0000040] /soc/gpu at simplebus1 not configured
[ 1.0000040] genfb0 at simplebus1
[ 1.0000040] wsdisplay0 at genfb0 kbdmux 1
[ 1.0000040] vchiq0 at simplebus1: BCM2835 VCHIQ
[ 1.0000040] armpmu0 at simplebus0: Performance Monitor Unit
[ 1.0000040] gpioleds0 at simplebus0: ACT
[ 1.0000040] bcmrng0 at simplebus1: RNG
[ 1.0000040] entropy: ready
[ 1.4296116] sdmmc0 at bcmsdhost0
[ 1.4296116] sdhc0: SDHC 3.0, rev 153, platform DMA, 200000 kHz, HS 3.3V,
re-tuning mode 1, 1024 byte blocks
[ 1.4396132] sdmmc1 at sdhc0 slot 0
[ 1.4596145] usb0 at dwctwo0: USB revision 2.0
[ 1.4696151] armpmu0: interrupting on local_intc irq 9
[ 1.4796185] uhub0 at usb0: NetBSD (0x0000) DWC2 root hub (0x0000), class
9/0, rev 2.00/1.00, addr 1
[ 1.5596215] sdmmc0: direct I/O error 5, r=3D6 p=3D0xffffc000b0fe3e5c wri=
te
[ 1.5696218] sdmmc0: couldn't enable card: 5
[ 1.6396270] sdmmc1: 4-bit width, 50.000 MHz
[ 1.6496270] sdmmc1: SDIO function
[ 1.6496270] bwfm0 at sdmmc1 function 1
[ 1.6596295] (manufacturer 0x2d0, product 0xa9a6) at sdmmc1 function 2
not configured
[ 1.6696310] (manufacturer 0x2d0, product 0xa9a6, standard function
interface code 0x2) at sdmmc1 function 3 not configured
[ 1.6807857] swwdog0: software watchdog initialized
[ 1.6807857] WARNING: 3 errors while detecting hardware; check system log=
.
[ 1.6896315] boot device: <unknown>
[ 1.6896315] unknown device major 0xffffffffffffffff
[ 2.6896969] unknown device major 0xffffffffffffffff
[ 3.6897623] unknown device major 0xffffffffffffffff
[ 4.6898281] unknown device major 0xffffffffffffffff
[ 5.6898932] unknown device major 0xffffffffffffffff
[ 6.6899576] unknown device major 0xffffffffffffffff
[ 7.6900234] unknown device major 0xffffffffffffffff
[ 8.6900887] unknown device major 0xffffffffffffffff
[ 9.6901540] unknown device major 0xffffffffffffffff
[ 10.6902196] unknown device major 0xffffffffffffffff
[ 11.6902858] unknown device major 0xffffffffffffffff
[ 12.6903514] unknown device major 0xffffffffffffffff
[ 13.6904171] unknown device major 0xffffffffffffffff
[ 14.6904828] unknown device major 0xffffffffffffffff
[ 15.6905485] unknown device major 0xffffffffffffffff
[ 16.6906144] unknown device major 0xffffffffffffffff
[ 17.6906794] unknown device major 0xffffffffffffffff
[ 18.6907446] unknown device major 0xffffffffffffffff
[ 19.6908105] unknown device major 0xffffffffffffffff
[ 20.6908759] unknown device major 0xffffffffffffffff
[ 21.6909417] unknown device major 0xffffffffffffffff
[ 21.7009432] root device:
[ 62.5036280] use one of: bwfm0 ddb halt reboot
[ 62.5036280] root device: ddb
Stopped in pid 0.0 (system) at netbsd:cpu_Debugger+0xc: ldp
x29, x30
, [sp],#16
db{2}> set $lines =3D 0
$lines 18 =3D 0
db{2}> set $maxwidth =3D 0
$maxwidth 50 =3D 0
db{2}> show kernhist/i
kernhist 'usbhist': at 0xffffc00000d0e058 total 50000 next free 366
db{2}> show kernhist usbhist
000001.451787 usb_allocmem#1@1: called!
000001.451789 usb_allocmem#1@1: adding fragments
000001.451791 usb_block_allocmem#1@1: called: size=3D8192 align=3D128 flags=
=3D0x2
000001.462478 usb_match#1@1: called!
000001.466272 usb_doattach#1@1: called!
000001.466282 usb_add_event#1@1: called!
000001.466285 usbd_new_device#1@1: called: bus=3D0xffff00003ac0b830 port=3D=
0
depth=3D0 speed=3D3
000001.466290 usbd_setup_pipe_flags#1@1: called: dev=3D0xffff00003a984f00
addr=3D0 iface=3D0 ep=3D0xffff00003a984f38
000001.466295 usbd_setup_pipe_flags#1@1: pipe=3D0xffff00003a918000
000001.466297 usbd_setup_pipe_flags#1@1: pipe=3D0xffff00003a918000
000001.466298 usbd_get_initial_ddesc#1@1: called: dev 0xffff00003a984f00
000001.466300 usbd_do_request_len#1@1: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3c48 flags=3D4 len=3D8
000001.466308 usbd_alloc_xfer#1@1: called: returns 0xffff00003a981040
000001.466309 usb_allocmem#2@1: called!
000001.466312 usbd_transfer#1@1: called: xfer =3D 0xffff00003a981040, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.466314 roothub_ctrl_start#1@1: called: type=3D0x80 request=3D0x6 len=
=3D0x8
value=3D0x100
000001.466315 roothub_ctrl_start#1@1: wValue=3D0x100
000001.466318 roothub_ctrl_start#1@1: xfer 0xffff00003a981040 buflen 8
actlen 8 err 0
000001.466319 usb_transfer_complete#1@1: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981040 status =3D 0 actlen =3D 8
000001.466320 usb_transfer_complete#1@1: xfer 0xffff00003a981040: repeat 0
new head =3D 0
000001.466321 usb_transfer_complete#1@1: xfer 0xffff00003a981040 doing done
0xffffc00000240980
000001.466323 usb_transfer_complete#1@1: xfer 0xffff00003a981040 doing
callback 0 status 0
000001.466323 usb_transfer_complete#1@1: <- done xfer 0xffff00003a981040,
wakeup
000001.466324 usbd_start_next#1@1: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.466326 usbd_transfer#1@1: <- done xfer 0xffff00003a981040, sync (err
0)
000001.466327 usbd_free_xfer#1@1: called: 0xffff00003a981040
000001.466329 usb_freemem#1@1: called!
000001.466332 usb_rem_task_wait#1@1: called!
000001.466339 usbd_new_device#1@1: adding unit addr=3D1, rev=3D200, class=
=3D9,
subclass=3D0
000001.466341 usbd_new_device#1@1: protocol=3D1, maxpacket=3D64, len=3D18, =
speed=3D3
000001.466346 usbd_ar_pipe#1@1: called: pipe =3D 0xffff00003a918000
000001.466348 usbd_close_pipe#1@1: called!
000001.466349 usb_rem_task_wait#2@1: called!
000001.466352 usbd_setup_pipe_flags#2@1: called: dev=3D0xffff00003a984f00
addr=3D0 iface=3D0 ep=3D0xffff00003a984f38
000001.466353 usbd_setup_pipe_flags#2@1: pipe=3D0xffff00003a918000
000001.466354 usbd_setup_pipe_flags#2@1: pipe=3D0xffff00003a918000
000001.466355 usbd_set_address#1@1: called: dev 0xffff00003a984f00 addr 1
000001.466356 usbd_do_request_len#2@1: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3c88 flags=3D0 len=3D0
000001.466359 usbd_alloc_xfer#2@1: called: returns 0xffff00003a981040
000001.466359 usbd_transfer#2@1: called: xfer =3D 0xffff00003a981040, flags=
=3D
0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.466360 roothub_ctrl_start#2@1: called: type=3D0 request=3D0x5 len=3D=
0
value=3D0x1
000001.466361 roothub_ctrl_start#2@1: UR_SET_ADDRESS, UT_WRITE_DEVICE: addr
1
000001.466362 roothub_ctrl_start#2@1: xfer 0xffff00003a981040 buflen 0
actlen 0 err 0
000001.466362 usb_transfer_complete#2@1: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981040 status =3D 0 actlen =3D 0
000001.466363 usb_transfer_complete#2@1: xfer 0xffff00003a981040: repeat 0
new head =3D 0
000001.466363 usb_transfer_complete#2@1: xfer 0xffff00003a981040 doing done
0xffffc00000240980
000001.466364 usb_transfer_complete#2@1: xfer 0xffff00003a981040 doing
callback 0 status 0
000001.466365 usb_transfer_complete#2@1: <- done xfer 0xffff00003a981040,
wakeup
000001.466365 usbd_start_next#2@1: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.466366 usbd_transfer#2@1: <- done xfer 0xffff00003a981040, sync (err
0)
000001.466366 usbd_free_xfer#2@1: called: 0xffff00003a981040
000001.466368 usb_rem_task_wait#3@1: called!
000001.476865 usb_task_thread#1@2: called: start taskq 0xffffc0000113be68
000001.476871 usb_task_thread#2@2: called: start taskq 0xffffc0000113bea8
000001.484200 usbd_ar_pipe#2@2: called: pipe =3D 0xffff00003a918000
000001.484201 usbd_close_pipe#2@2: called!
000001.484202 usb_rem_task_wait#4@2: called!
000001.484204 usbd_setup_pipe_flags#3@2: called: dev=3D0xffff00003a984f00
addr=3D1 iface=3D0 ep=3D0xffff00003a984f38
000001.484205 usbd_setup_pipe_flags#3@2: pipe=3D0xffff00003a918000
000001.484207 usbd_setup_pipe_flags#3@2: pipe=3D0xffff00003a918000
000001.484209 usbd_reload_device_desc#1@2: called!
000001.484210 usbd_get_device_desc#1@2: called!
000001.484212 usbd_get_desc#1@2: called: type=3D1, index=3D0, len=3D18
000001.484212 usbd_do_request_len#3@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3c28 flags=3D0 len=3D12
000001.484218 usbd_alloc_xfer#3@2: called: returns 0xffff00003a981190
000001.484219 usb_allocmem#3@2: called!
000001.484221 usbd_transfer#3@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.484222 roothub_ctrl_start#3@2: called: type=3D0x80 request=3D0x6
len=3D0x12 value=3D0x100
000001.484223 roothub_ctrl_start#3@2: wValue=3D0x100
000001.484224 roothub_ctrl_start#3@2: xfer 0xffff00003a981190 buflen 18
actlen 18 err 0
000001.484225 usb_transfer_complete#3@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 18
000001.484226 usb_transfer_complete#3@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484226 usb_transfer_complete#3@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484227 usb_transfer_complete#3@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484228 usb_transfer_complete#3@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484229 usbd_start_next#3@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484229 usbd_transfer#3@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484230 usbd_free_xfer#3@2: called: 0xffff00003a981190
000001.484231 usb_freemem#2@2: called!
000001.484233 usb_rem_task_wait#5@2: called!
000001.484240 usbd_new_device#1@2: new dev (addr 1),
dev=3D0xffff00003a984f00, parent=3D0xffff00003a94c400
000001.484244 usbd_get_string0#1@2: called!
000001.484245 usbd_get_string_desc#1@2: called!
000001.484246 usbd_do_request_len#4@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484248 usbd_alloc_xfer#4@2: called: returns 0xffff00003a981190
000001.484249 usb_allocmem#4@2: called!
000001.484250 usb_allocmem#4@2: large alloc 254
000001.484250 usb_block_allocmem#2@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484273 usbd_transfer#4@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484274 roothub_ctrl_start#4@2: called: type=3D0x80 request=3D0x6 len=
=3D0x2
value=3D0x300
000001.484275 roothub_ctrl_start#4@2: wValue=3D0x300
000001.484276 roothub_ctrl_start#4@2: xfer 0xffff00003a981190 buflen 2
actlen 2 err 0
000001.484277 usb_transfer_complete#4@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 2
000001.484277 usb_transfer_complete#4@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484278 usb_transfer_complete#4@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484278 usb_transfer_complete#4@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484279 usb_transfer_complete#4@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484279 usbd_start_next#4@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484280 usbd_transfer#4@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484281 usbd_free_xfer#4@2: called: 0xffff00003a981190
000001.484281 usb_freemem#3@2: called!
000001.484282 usb_freemem#3@2: large free
000001.484283 usb_block_freemem#1@2: called: size=3D8192
000001.484284 usb_rem_task_wait#6@2: called!
000001.484287 usbd_do_request_len#5@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484290 usbd_alloc_xfer#5@2: called: returns 0xffff00003a981190
000001.484290 usb_allocmem#5@2: called!
000001.484291 usb_allocmem#5@2: large alloc 254
000001.484292 usb_block_allocmem#3@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484293 usbd_transfer#5@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484293 roothub_ctrl_start#5@2: called: type=3D0x80 request=3D0x6 len=
=3D0x4
value=3D0x300
000001.484294 roothub_ctrl_start#5@2: wValue=3D0x300
000001.484295 roothub_ctrl_start#5@2: xfer 0xffff00003a981190 buflen 4
actlen 4 err 0
000001.484295 usb_transfer_complete#5@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 4
000001.484296 usb_transfer_complete#5@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484297 usb_transfer_complete#5@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484297 usb_transfer_complete#5@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484298 usb_transfer_complete#5@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484298 usbd_start_next#5@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484299 usbd_transfer#5@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484300 usbd_free_xfer#5@2: called: 0xffff00003a981190
000001.484300 usb_freemem#4@2: called!
000001.484301 usb_freemem#4@2: large free
000001.484302 usb_block_freemem#2@2: called: size=3D8192
000001.484303 usb_rem_task_wait#7@2: called!
000001.484305 usbd_get_string_desc#2@2: called!
000001.484306 usbd_do_request_len#6@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484309 usbd_alloc_xfer#6@2: called: returns 0xffff00003a981190
000001.484309 usb_allocmem#6@2: called!
000001.484310 usb_allocmem#6@2: large alloc 254
000001.484310 usb_block_allocmem#4@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484311 usbd_transfer#6@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484312 roothub_ctrl_start#6@2: called: type=3D0x80 request=3D0x6 len=
=3D0x2
value=3D0x301
000001.484313 roothub_ctrl_start#6@2: wValue=3D0x301
000001.484314 roothub_ctrl_start#6@2: xfer 0xffff00003a981190 buflen 2
actlen 2 err 0
000001.484314 usb_transfer_complete#6@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 2
000001.484315 usb_transfer_complete#6@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484315 usb_transfer_complete#6@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484316 usb_transfer_complete#6@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484317 usb_transfer_complete#6@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484317 usbd_start_next#6@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484318 usbd_transfer#6@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484318 usbd_free_xfer#6@2: called: 0xffff00003a981190
000001.484319 usb_freemem#5@2: called!
000001.484320 usb_freemem#5@2: large free
000001.484320 usb_block_freemem#3@2: called: size=3D8192
000001.484321 usb_rem_task_wait#8@2: called!
000001.484324 usbd_do_request_len#7@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484326 usbd_alloc_xfer#7@2: called: returns 0xffff00003a981190
000001.484327 usb_allocmem#7@2: called!
000001.484327 usb_allocmem#7@2: large alloc 254
000001.484328 usb_block_allocmem#5@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484329 usbd_transfer#7@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484329 roothub_ctrl_start#7@2: called: type=3D0x80 request=3D0x6 len=
=3D0xe
value=3D0x301
000001.484330 roothub_ctrl_start#7@2: wValue=3D0x301
000001.484331 roothub_ctrl_start#7@2: xfer 0xffff00003a981190 buflen 14
actlen 14 err 0
000001.484331 usb_transfer_complete#7@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 14
000001.484332 usb_transfer_complete#7@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484332 usb_transfer_complete#7@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484333 usb_transfer_complete#7@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484334 usb_transfer_complete#7@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484334 usbd_start_next#7@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484335 usbd_transfer#7@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484335 usbd_free_xfer#7@2: called: 0xffff00003a981190
000001.484336 usb_freemem#6@2: called!
000001.484337 usb_freemem#6@2: large free
000001.484337 usb_block_freemem#4@2: called: size=3D8192
000001.484338 usb_rem_task_wait#9@2: called!
000001.484343 usbd_get_string0#2@2: called!
000001.484344 usbd_get_string_desc#3@2: called!
000001.484344 usbd_do_request_len#8@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484347 usbd_alloc_xfer#8@2: called: returns 0xffff00003a981190
000001.484348 usb_allocmem#8@2: called!
000001.484348 usb_allocmem#8@2: large alloc 254
000001.484349 usb_block_allocmem#6@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484350 usbd_transfer#8@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484350 roothub_ctrl_start#8@2: called: type=3D0x80 request=3D0x6 len=
=3D0x2
value=3D0x302
000001.484351 roothub_ctrl_start#8@2: wValue=3D0x302
000001.484352 roothub_ctrl_start#8@2: xfer 0xffff00003a981190 buflen 2
actlen 2 err 0
000001.484353 usb_transfer_complete#8@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 2
000001.484353 usb_transfer_complete#8@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484354 usb_transfer_complete#8@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484355 usb_transfer_complete#8@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484355 usb_transfer_complete#8@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484356 usbd_start_next#8@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484356 usbd_transfer#8@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484357 usbd_free_xfer#8@2: called: 0xffff00003a981190
000001.484358 usb_freemem#7@2: called!
000001.484358 usb_freemem#7@2: large free
000001.484359 usb_block_freemem#5@2: called: size=3D8192
000001.484360 usb_rem_task_wait#10@2: called!
000001.484363 usbd_do_request_len#9@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe
000001.484365 usbd_alloc_xfer#9@2: called: returns 0xffff00003a981190
000001.484365 usb_allocmem#9@2: called!
000001.484366 usb_allocmem#9@2: large alloc 254
000001.484367 usb_block_allocmem#7@2: called: size=3D8192 align=3D0 flags=
=3D0
000001.484367 usbd_transfer#9@2: called: xfer =3D 0xffff00003a981190, flags=
=3D
0x6, pipe =3D 0xffff00003a918000, running =3D 0
000001.484368 roothub_ctrl_start#9@2: called: type=3D0x80 request=3D0x6
len=3D0x1c value=3D0x302
000001.484368 roothub_ctrl_start#9@2: wValue=3D0x302
000001.484370 roothub_ctrl_start#9@2: xfer 0xffff00003a981190 buflen 18
actlen 28 err 0
000001.484370 usb_transfer_complete#9@2: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 28
000001.484371 usb_transfer_complete#9@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.484372 usb_transfer_complete#9@2: xfer 0xffff00003a981190 doing done
0xffffc00000240980
000001.484372 usb_transfer_complete#9@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.484373 usb_transfer_complete#9@2: <- done xfer 0xffff00003a981190,
wakeup
000001.484373 usbd_start_next#9@2: called: pipe =3D 0xffff00003a918000, xfe=
r
=3D 0
000001.484374 usbd_transfer#9@2: <- done xfer 0xffff00003a981190, sync (err
0)
000001.484375 usbd_free_xfer#9@2: called: 0xffff00003a981190
000001.484375 usb_freemem#8@2: called!
000001.484376 usb_freemem#8@2: large free
000001.484376 usb_block_freemem#6@2: called: size=3D8192
000001.484378 usb_rem_task_wait#11@2: called!
000001.484385 usbd_get_string0#3@2: called!
000001.484409 usb_add_event#2@2: called!
000001.492995 usbd_set_config_index#1@2: called: dev=3D0xffff00003a984f00
index=3D0
000001.492997 usbd_get_config_desc#1@2: called: confidx=3D0
000001.492998 usbd_get_desc#2@2: called: type=3D2, index=3D0, len=3D9
000001.492998 usbd_do_request_len#10@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3978 flags=3D0 len=3D9
000001.493003 usbd_alloc_xfer#10@2: called: returns 0xffff00003a981190
000001.493003 usb_allocmem#10@2: called!
000001.493006 usbd_transfer#10@2: called: xfer =3D 0xffff00003a981190, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493007 roothub_ctrl_start#10@2: called: type=3D0x80 request=3D0x6
len=3D0x9 value=3D0x200
000001.493007 roothub_ctrl_start#10@2: wValue=3D0x200
000001.493008 roothub_ctrl_start#10@2: xfer 0xffff00003a981190 buflen 9
actlen 9 err 0
000001.493009 usb_transfer_complete#10@2: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 9
000001.493009 usb_transfer_complete#10@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.493010 usb_transfer_complete#10@2: xfer 0xffff00003a981190 doing
done 0xffffc00000240980
000001.493011 usb_transfer_complete#10@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.493011 usb_transfer_complete#10@2: <- done xfer 0xffff00003a981190,
wakeup
000001.493012 usbd_start_next#10@2: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493013 usbd_transfer#10@2: <- done xfer 0xffff00003a981190, sync
(err 0)
000001.493013 usbd_free_xfer#10@2: called: 0xffff00003a981190
000001.493014 usb_freemem#9@2: called!
000001.493015 usb_rem_task_wait#12@2: called!
000001.493019 usbd_get_desc#3@2: called: type=3D2, index=3D0, len=3D25
000001.493019 usbd_do_request_len#11@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa39c8 flags=3D0 len=3D19
000001.493022 usbd_alloc_xfer#11@2: called: returns 0xffff00003a981190
000001.493022 usb_allocmem#11@2: called!
000001.493024 usbd_transfer#11@2: called: xfer =3D 0xffff00003a981190, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493025 roothub_ctrl_start#11@2: called: type=3D0x80 request=3D0x6
len=3D0x19 value=3D0x200
000001.493026 roothub_ctrl_start#11@2: wValue=3D0x200
000001.493026 roothub_ctrl_start#11@2: xfer 0xffff00003a981190 buflen 25
actlen 25 err 0
000001.493027 usb_transfer_complete#11@2: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 25
000001.493028 usb_transfer_complete#11@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.493028 usb_transfer_complete#11@2: xfer 0xffff00003a981190 doing
done 0xffffc00000240980
000001.493029 usb_transfer_complete#11@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.493030 usb_transfer_complete#11@2: <- done xfer 0xffff00003a981190,
wakeup
000001.493030 usbd_start_next#11@2: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493031 usbd_transfer#11@2: <- done xfer 0xffff00003a981190, sync
(err 0)
000001.493033 usbd_free_xfer#11@2: called: 0xffff00003a981190
000001.493034 usb_freemem#10@2: called!
000001.493037 usb_rem_task_wait#13@2: called!
000001.493041 usbd_set_config_index#1@2: addr 1 cno=3D1 attr=3D0xc0,
selfpowered=3D1
000001.493041 usbd_set_config_index#1@2: max power=3D0
000001.493042 usbd_set_config_index#1@2: set config 1
000001.493043 usbd_set_config#1@2: called: dev 0xffff00003a984f00 conf 1
000001.493044 usbd_do_request_len#12@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa39c8 flags=3D0 len=3D0
000001.493046 usbd_alloc_xfer#12@2: called: returns 0xffff00003a981190
000001.493047 usbd_transfer#12@2: called: xfer =3D 0xffff00003a981190, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493048 roothub_ctrl_start#12@2: called: type=3D0 request=3D0x9 len=
=3D0
value=3D0x1
000001.493048 roothub_ctrl_start#12@2: xfer 0xffff00003a981190 buflen 0
actlen 0 err 0
000001.493049 usb_transfer_complete#12@2: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 0
000001.493049 usb_transfer_complete#12@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.493050 usb_transfer_complete#12@2: xfer 0xffff00003a981190 doing
done 0xffffc00000240980
000001.493050 usb_transfer_complete#12@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.493051 usb_transfer_complete#12@2: <- done xfer 0xffff00003a981190,
wakeup
000001.493052 usbd_start_next#12@2: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493052 usbd_transfer#12@2: <- done xfer 0xffff00003a981190, sync
(err 0)
000001.493053 usbd_free_xfer#12@2: called: 0xffff00003a981190
000001.493054 usb_rem_task_wait#14@2: called!
000001.493059 usbd_fill_iface_data#1@2: called: ifaceidx=3D0 altidx=3D0
000001.493060 usbd_find_idesc#1@2: called: iface/alt idx 0/0
000001.493064 usbd_do_request_len#13@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3ad0 flags=3D0 len=3D9
000001.493066 usbd_alloc_xfer#13@2: called: returns 0xffff00003a981190
000001.493067 usb_allocmem#12@2: called!
000001.493069 usbd_transfer#13@2: called: xfer =3D 0xffff00003a981190, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493070 roothub_ctrl_start#13@2: called: type=3D0xa0 request=3D0x6
len=3D0x9 value=3D0x2900
000001.493071 roothub_ctrl_start#13@2: xfer 0xffff00003a981190 buflen 9
actlen 9 err 0
000001.493072 usb_transfer_complete#13@2: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 9
000001.493072 usb_transfer_complete#13@2: xfer 0xffff00003a981190: repeat 0
new head =3D 0
000001.493073 usb_transfer_complete#13@2: xfer 0xffff00003a981190 doing
done 0xffffc00000240980
000001.493074 usb_transfer_complete#13@2: xfer 0xffff00003a981190 doing
callback 0 status 0
000001.493074 usb_transfer_complete#13@2: <- done xfer 0xffff00003a981190,
wakeup
000001.493075 usbd_start_next#13@2: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493075 usbd_transfer#13@2: <- done xfer 0xffff00003a981190, sync
(err 0)
000001.493076 usbd_free_xfer#13@2: called: 0xffff00003a981190
000001.493077 usb_freemem#11@2: called!
000001.493078 usb_rem_task_wait#15@2: called!
000001.493122 usbd_open_pipe_intr#1@2: called: address =3D 0x81 flags =3D 0=
x84
len =3D 1
000001.493123 usbd_open_pipe_ival#1@2: called: iface =3D 0xffff00003aaed8c0
address =3D 0x81 flags =3D 0x81
000001.493125 usbd_setup_pipe_flags#4@2: called: dev=3D0xffff00003a984f00
addr=3D1 iface=3D0xffff00003aaed8c0 ep=3D0xffff00003afde3b0
000001.493127 usbd_setup_pipe_flags#4@2: pipe=3D0xffff00003a918700
000001.493128 usbd_setup_pipe_flags#4@2: pipe=3D0xffff00003a918700
000001.493132 usbd_alloc_xfer#14@2: called: returns 0xffff00003a981190
000001.493132 usb_allocmem#13@2: called!
000001.493135 usbd_transfer#14@2: called: xfer =3D 0xffff00003a981190, flag=
s
=3D 0x84, pipe =3D 0xffff00003a918700, running =3D 0
000001.493136 usbd_transfer#14@2: <- done xfer 0xffff00003a981190, not sync
(err 1)
000001.493144 usb_add_event#3@2: called!
000001.493148 usbd_set_port_feature#1@2: called: dev 0xffff00003a984f00
port 8 sel
000001.493148 usbd_do_request_len#14@2: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fa3a68 flags=3D0 len=3D0
000001.493153 usbd_alloc_xfer#15@2: called: returns 0xffff00003a9812e0
000001.493154 usbd_transfer#15@2: called: xfer =3D 0xffff00003a9812e0, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493155 roothub_ctrl_start#14@2: called: type=3D0x23 request=3D0x3 le=
n=3D0
value=3D0x8
000001.493155 roothub_ctrl_start#14@2: xfer 0xffff00003a9812e0 buflen -1
actlen 0 err 0
000001.493156 usb_transfer_complete#14@2: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a9812e0 status =3D 0 actlen =3D 0
000001.493157 usb_transfer_complete#14@2: xfer 0xffff00003a9812e0: repeat 0
new head =3D 0
000001.493157 usb_transfer_complete#14@2: xfer 0xffff00003a9812e0 doing
done 0xffffc00000240980
000001.493158 usb_transfer_complete#14@2: xfer 0xffff00003a982e0 doing
callback 0 status 0
000001.493159 usb_transfer_complete#14@2: <- done xfer 0xffff00003a9812e0,
wakeup
000001.493161 usbd_start_next#14@2: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493162 usbd_transfer#15@2: <- done xfer 0xffff00003a9812e0, sync
(err 0)
000001.493163 usbd_free_xfer#14@2: called: 0xffff00003a9812e0
000001.493165 usb_rem_task_wait#16@2: called!
000001.493195 usb_event_thread#1@0: called!
000001.493197 usb_discover#1@0: called!
000001.493199 usbd_get_hub_status#1@0: called: dev 0xffff00003a984f00
000001.493200 usbd_do_request_len#15@0: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fbbd78 flags=3D0 len=3D4
000001.493207 usbd_alloc_xfer#16@0: called: returns 0xffff00003a981430
000001.493207 usb_allocmem#14@0: called!
000001.493210 usbd_transfer#16@0: called: xfer =3D 0xffff00003a981430, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493211 roothub_ctrl_start#15@0: called: type=3D0xa0 request=3D0 len=
=3D0x4
value=3D0
000001.493212 roothub_ctrl_start#15@0: xfer 0xffff00003a981430 buflen -1
actlen 4 err 0
000001.493213 usb_transfer_complete#15@0: called: pipe =3D 0xffff00003a9180=
00
xfer =3D 0xffff00003a981430 status =3D 0 actlen =3D 4
000001.493213 usb_transfer_complete#15@0: xfer 0xffff00003a981430: repeat 0
new head =3D 0
000001.493214 usb_transfer_complete#15@0: xfer 0xffff00003a981430 doing
done 0xffffc00000240980
000001.493215 usb_transfer_complete#15@0: xfer 0xffff00003a981430 dong
callback 0 status 0
000001.493215 usb_transfer_complete#15@0: <- done xfer 0xffff00003a981430,
wakeup
000001.493216 usbd_start_next#15@0: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493217 usbd_transfer#16@0: <- done xfer 0xffff00003a981430, sync
(err 0)
000001.493218 usbd_free_xfer#15@0: called: 0xffff00003a981430
000001.493218 usb_freemem#12@0: called!
000001.493220 usb_rem_task_wait#17@0: called!
000001.493229 usbd_get_port_status#1@0: called: dev 0xffff00003a984f00 port
1
000001.493230 usbd_do_request_len#16@0: called: dev=3D0xffff00003a984f00
req=3Dffffc000b0fbbd78 flags=3D0 len=3D4
000001.493233 usbd_alloc_xfer#17@0: called: returns 0xffff00003a981430
000001.493233 usb_allocmem#15@0: called!
000001.493235 usbd_transfer#17@0: called: xfer =3D 0xffff00003a981430, flag=
s
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0
000001.493236 roothub_ctrl_start#16@0: called: type=3D0xa3 request=3D0 len=
=3D0x4
value=3D0
000001.493237 roothub_ctrl_start#16@0: xfer 0xffff00003a981430 buflen -1
actlen 4 err 0
00000.493237 usb_transfer_complete#16@0: called: pipe =3D 0xffff00003a91800=
0
xfer =3D 0xffff00003a981430 status =3D 0 actlen =3D 4
000001.493238 usb_transfer_complete#16@0: xfer 0xffff00003a981430: repeat 0
new head =3D 0
000001.493239 usb_transfer_complete#16@0: xfer 0xffff00003a981430 doing
done 0xffffc00000240980
000001.493240 usb_transfer_complete#16@0: xfer 0xffff00003a981430 doing
callback 0 stats 0
000001.493241 usb_transfer_complete#16@0: <- done xfer 0xffff00003a981430,
wakeup
000001.493241 usbd_start_next#16@0: called: pipe =3D 0xffff00003a918000, xf=
er
=3D 0
000001.493242 usbd_transfer#17@0: <- done xfer 0xffff00003a981430, sync
(err 0)
000001.493242 usbd_free_xfer#16@0: called: 0xffff00003a981430
000001.493243 usb_freemem#13@0: called!
000001.493245 usb_rem_task_wait#18@0: called!
000001.493249 usb_discover#2@0: called!
000061.493583 usb_discover#3@0: called!
000121.497526 usb_discover#4@0: called!
000181.501472 usb_discover#5@0: called!
000241.505422 usb_discover#6@0: called!
000301.509371 usb_discover#7@0: called!
000361.513318 usb_discover#8@0: called!
000421.517263 usb_discover#9@0: called!
000481.521199 usb_discover#10@0: called!
000541.525142 usb_discover#11@0: called!
000601.529086 usb_discover#12@0: called!
000661.533028 usb_discover#13@0: called!
000721.536973 usb_discover#14@0: called!
000781.540918 usb_discover#15@0: called!
000841.544863 usb_discover#16@0: called!
000901.548806 usb_discover#17@0: called!
000961.552748 usb_discover#18@0: called!
db{2}>
On Tue, Aug 4, 2026 at 11:35=E2=80=AFAM Nick Hudson via gnats <
gnats-admin%netbsd.org@localhost> wrote:
>
> The following reply was made to PR port-arm/60021; it has been noted by
GNATS.
>
> From: Nick Hudson <nick.hudson%gmx.co.uk@localhost>
> To: Taylor R Campbell <riastradh%NetBSD.org@localhost>
> Cc: mac%culver.net@localhost,
> "gnats-bugs%netbsd.org@localhost" <gnats-bugs%NetBSD.org@localhost>,
> "netbsd-bugs%netbsd.org@localhost" <netbsd-bugs%NetBSD.org@localhost>
> Subject: Re: port-arm/60021: USB-only boot: uhub0 attaches but uhub1 neve=
r
> appears, no hotplug events; SD-boot sees hub+umass fine
> Date: Tue, 4 Aug 2026 19:32:12 +0100
>
> > On 4 Aug 2026, at 14:34, Taylor R Campbell <riastradh%NetBSD.org@localhost> =3D
> wrote:
> >=3D20
> >> Date: Sat, 21 Feb 2026 10:39:41 +0000
> >> From: Nick Hudson <nick.hudson%gmx.co.uk@localhost>
> >>=3D20
> >> This is almost certainly that autoconf doesn't wait (long enough) for
> >> sub-ordintate hubs
> >>=3D20
> >> https://nxr.netbsd.org/xref/src/sys/dev/usb/uhub.c#880
> >>=3D20
> >> 880 mutex_enter(&sc->sc_lock);
> >> 881 sc->sc_explorepending =3D3D false;
> >> 882 for (int i =3D3D 0; i < sc->sc_statuslen; i++) {
> >> 883 if (sc->sc_statuspend[i] !=3D3D 0) {
> >> 884 memcpy(sc->sc_status, sc->sc_statuspend,
> >> 885 sc->sc_statuslen);
> >> 886 memset(sc->sc_statuspend, 0, sc->sc_statuslen);
> >> 887 usb_needs_explore(sc->sc_hub);
> >> 888 break;
> >> 889 }
> >> 890 }
> >> 891 mutex_exit(&sc->sc_lock);
> >> 892 if (sc->sc_first_explore) {
> >> 893 config_pending_decr(sc->sc_dev);
> >> 894 sc->sc_first_explore =3D3D false;
> >> 895 }
> >=3D20
> > I don't understand, doesn't it wait for subordinate hubs?
>
> Sure, but not long enough...
>
> > ... Maybe the
> > USB hub just doesn't report the device ready at first?
>
> Because there=3DE2=3D80=3D99s no guarantee (afaik) that the root hub wil=
l see =3D
> the built-in hub immediately.
--0000000000001c50be0658580742
Content-Type: text/html; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
<div dir=3D"ltr"><span class=3D"gmail_default" style=3D"font-family:arial,h=
elvetica,sans-serif;font-size:small"></span>Here is the output with usb deb=
ug:<br><br><br>RPi3B+ USB boot diagnostic kernel<br><br>Wed Aug =C2=A05 20:=
44:41 UTC 2026<br><br>NetBSD <a href=3D"http://SS.Culver.Net";>SS.Culver.Net=
</a> 11.0_RC5 NetBSD 11.0_RC5 (GENERIC) #0: Tue Jun 16 15:48:07 UTC 2026 =
=C2=A0mkrepro%mkrepro.NetBSD.org@localhost:/usr/src/sys/arch/amd64/compile/GENERIC am=
d64<br><br>Target: MACHINE=3Devbarm MACHINE_ARCH=3Daarch64<br>Source branch=
: netbsd-11<br>Kernel configuration: GENERIC64_USBDEBUG<br><br>Kernel hashe=
s:<br>SHA256 (/root/obj-rpi3b-usbdebug/sys/arch/evbarm/compile/GENERIC64_US=
BDEBUG/netbsd) =3D 96bdfcf491362c83a1eedd251c5de5bb44f9f8a565a351a6ee58e652=
cbfea91d<br>SHA256 (/root/obj-rpi3b-usbdebug/sys/arch/evbarm/compile/GENERI=
C64_USBDEBUG/netbsd.img) =3D 6b0a14b4faf31249a9fd583c2e8ead68cf3fe4501484d9=
cb688992630a2f9773<br><br>Relevant CVS revisions:<br>File: usb.c =C2=A0 =C2=
=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 Status: Up-to-date<br>=C2=A0 =C2=A0Working =
revision: =C2=A0 =C2=A01.203<br>=C2=A0 =C2=A0Sticky Tag: =C2=A0 =C2=A0 =C2=
=A0 =C2=A0 =C2=A0netbsd-11 (branch: 1.203.4)<br>File: uhub.c =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0Status: Up-to-date<br>=C2=A0 =C2=A0Working revis=
ion: =C2=A0 =C2=A01.162<br>=C2=A0 =C2=A0Sticky Tag: =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0netbsd-11 (branch: 1.162.4)<br>File: usb_subr.c =C2=A0 =C2=A0 =
=C2=A0 =C2=A0Status: Up-to-date<br>=C2=A0 =C2=A0Working revision: =C2=A0 =
=C2=A01.279.4.1<br>=C2=A0 =C2=A0Sticky Tag: =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=
=A0netbsd-11 (branch: 1.279.4)<br><br>=E2=96=92[ =C2=A0 1.0000000] NetBSD/e=
vbarm (fdt) booting ...<br>[ =C2=A0 1.0000000] Copyright (c) 1996, 1997, 19=
98, 1999, 2000, 2001, 2002, 2003,<br>[ =C2=A0 1.0000000] =C2=A0 =C2=A0 2004=
, 2005, 2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013,<br>[ =C2=A0 1.00000=
00] =C2=A0 =C2=A0 2014, 2015, 2016, 2017, 2018, 2019, 2020, 2021, 2022, 202=
3,<br>[ =C2=A0 1.0000000] =C2=A0 =C2=A0 2024, 2025, 2026<br>[ =C2=A0 1.0000=
000] =C2=A0 =C2=A0 The NetBSD Foundation, Inc.=C2=A0 All rights reserved.<b=
r>[ =C2=A0 1.0000000] Copyright (c) 1982, 1986, 1989, 1991, 1993<br>[ =C2=
=A0 1.0000000] =C2=A0 =C2=A0 The Regents of the University of California.=
=C2=A0 All rights reserved.<br><br>[ =C2=A0 1.0000000] NetBSD 11.0_STABLE (=
GENERIC64_USBDEBUG) #0: Wed Aug =C2=A05 19:49:20 UTC 2026<br>[ =C2=A0 1.000=
0000] =C2=A0root%SS.Culver.Net@localhost:/root/obj-rpi3b-usbdebug/sys/arch/evbarm/com=
pile/GENERIC64_USBDEBUG<br>[ =C2=A0 1.0000000] total memory =3D 925 MB<br>[=
=C2=A0 1.0000000] avail memory =3D 890 MB<br>[ =C2=A0 1.0000000] armfdt0 (=
root)<br>[ =C2=A0 1.0000000] simplebus0 at armfdt0: Raspberry Pi 3 Model B =
Plus Rev 1.4<br>[ =C2=A0 1.0000000] simplebus1 at simplebus0<br>[ =C2=A0 1.=
0000000] simplebus2 at simplebus0<br>[ =C2=A0 1.0000000] cpus0 at simplebus=
0<br>[ =C2=A0 1.0000000] simplebus3 at simplebus0<br>[ =C2=A0 1.0000000] cp=
u0 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0x0<br>[ =C2=A0 1.0000000] cpu0=
: package 0, core 0, smt 0, numa 0<br>[ =C2=A0 1.0000000] cpu1 at cpus0: Ar=
m Cortex-A53 r0p4 (v8-A), id 0x1<br>[ =C2=A0 1.0000000] cpu1: package 0, co=
re 1, smt 0, numa 0<br>[ =C2=A0 1.0000000] cpu2 at cpus0: Arm Cortex-A53 r0=
p4 (v8-A), id 0x2<br>[ =C2=A0 1.0000000] cpu2: package 0, core 2, smt 0, nu=
ma 0<br>[ =C2=A0 1.0000000] cpu3 at cpus0: Arm Cortex-A53 r0p4 (v8-A), id 0=
x3<br>[ =C2=A0 1.0000000] cpu3: package 0, core 3, smt 0, numa 0<br>[ =C2=
=A0 1.0000000] bcmicu0 at simplebus1<br>[ =C2=A0 1.0000000] fclock0 at simp=
lebus2: 19200000 Hz fixed clock (osc)<br>[ =C2=A0 1.0000000] bcmcprman0 at =
simplebus1: BCM283x Clock Controller<br>[ =C2=A0 1.0000000] syscon0 at simp=
lebus1: couldn't get registers<br>[ =C2=A0 1.0000000] bcmaux0 at simple=
bus1<br>[ =C2=A0 1.0000000] fclock1 at simplebus2: 480000000 Hz fixed clock=
(otg)<br>[ =C2=A0 1.0000000] bcmicu1 at simplebus1: Multiprocessor<br>[ =
=C2=A0 1.0000000] gtmr0 at simplebus0: Generic Timer<br>[ =C2=A0 1.0000000]=
gtmr0: interrupting on local_intc irq 3<br>[ =C2=A0 1.0000000] armgtmr0 at=
gtmr0: Generic Timer (19200 kHz, virtual)<br>[ =C2=A0 1.0000040] bcmgpio0 =
at simplebus1: GPIO controller 2835<br>[ =C2=A0 1.0000040] bcmgpio0: pins 0=
..31 interrupting on icu irq 49<br>[ =C2=A0 1.0000040] bcmgpio0: pins 32..5=
4 interrupting on icu irq 50<br>[ =C2=A0 1.0000040] gpio0 at bcmgpio0: 54 p=
ins<br>[ =C2=A0 1.0000040] plcom0 at simplebus1: ARM PL011 UART<br>[ =C2=A0=
1.0000040] plcom0: txfifo 16 bytes<br>[ =C2=A0 1.0000040] plcom0: interrup=
ting on icu irq 57<br>[ =C2=A0 1.0000040] com0 at simplebus1: BCM AUX UART,=
1-byte FIFO<br>[ =C2=A0 1.0000040] com0: console<br>[ =C2=A0 1.0000040] co=
m0: interrupting on icu irq 29, clock 800000000 Hz<br>[ =C2=A0 1.0000040] m=
mcpwrseq0 at simplebus0: couldn't get reset GPIOs<br>[ =C2=A0 1.0000040=
] /soc/thermal@7e212000 at simplebus1 not configured<br>[ =C2=A0 1.0000040]=
bcmdmac0 at simplebus1: DMA0 DMA2 DMA4 DMA5 DMA6 DMA7 DMA8 DMA9 DMA10 DMA1=
1<br>[ =C2=A0 1.0000040] /soc/power at simplebus1 not configured<br>[ =C2=
=A0 1.0000040] /phy at simplebus0 not configured<br>[ =C2=A0 1.0000040] bsc=
iic0 at simplebus1: Broadcom Serial Controller<br>[ =C2=A0 1.0000040] bscii=
c0: interrupting on icu irq 53<br>[ =C2=A0 1.0000040] iic0 at bsciic0: I2C =
bus<br>[ =C2=A0 1.0000040] bcmmbox0 at simplebus1: VC mailbox<br>[ =C2=A0 1=
.0000040] bcmmbox0: interrupting on icu irq 65<br>[ =C2=A0 1.0000040] vcmbo=
x0 at bcmmbox0<br>[ =C2=A0 1.0000040] /soc/timer@7e003000 at simplebus1 not=
configured<br>[ =C2=A0 1.0000040] /soc/txp@7e004000 at simplebus1 not conf=
igured<br>[ =C2=A0 1.0000040] bcmsdhost0 at simplebus1: SD HOST controller<=
br>[ =C2=A0 1.0000040] bcmsdhost0: interrupting on icu irq 56<br>[ =C2=A0 1=
.0000040] bsciic1 at simplebus1: Broadcom Serial Controller<br>[ =C2=A0 1.0=
000040] bsciic1: interrupting on icu irq 53<br>[ =C2=A0 1.0000040] iic1 at =
bsciic1: I2C bus<br>[ =C2=A0 1.0000040] /soc/pwm@7e20c000 at simplebus1 not=
configured<br>[ =C2=A0 1.0000040] sdhc0 at simplebus1: SDHC controller<br>=
[ =C2=A0 1.0000040] sdhc0: interrupting on icu irq 62<br>[ =C2=A0 1.0000040=
] bsciic2 at simplebus1: Broadcom Serial Controller<br>[ =C2=A0 1.0000040] =
bsciic2: interrupting on icu irq 53<br>[ =C2=A0 1.0000040] iic2 at bsciic2:=
I2C bus<br>[ =C2=A0 1.0000040] dwctwo0 at simplebus1: USB controller<br>[ =
=C2=A0 1.0000040] dwctwo0: interrupting on icu irq 9<br>[ =C2=A0 1.0000040]=
bcmpmwdog0 at simplebus1: Power management, Reset and Watchdog controller<=
br>[ =C2=A0 1.0000040] /soc/vec@7e806000 at simplebus1 not configured<br>[ =
=C2=A0 1.0000040] /soc/hdmi@7e902000 at simplebus1 not configured<br>[ =C2=
=A0 1.0000040] /soc/gpu at simplebus1 not configured<br>[ =C2=A0 1.0000040]=
genfb0 at simplebus1<br>[ =C2=A0 1.0000040] wsdisplay0 at genfb0 kbdmux 1<=
br>[ =C2=A0 1.0000040] vchiq0 at simplebus1: BCM2835 VCHIQ<br>[ =C2=A0 1.00=
00040] armpmu0 at simplebus0: Performance Monitor Unit<br>[ =C2=A0 1.000004=
0] gpioleds0 at simplebus0: ACT<br>[ =C2=A0 1.0000040] bcmrng0 at simplebus=
1: RNG<br>[ =C2=A0 1.0000040] entropy: ready<br>[ =C2=A0 1.4296116] sdmmc0 =
at bcmsdhost0<br>[ =C2=A0 1.4296116] sdhc0: SDHC 3.0, rev 153, platform DMA=
, 200000 kHz, HS 3.3V, re-tuning mode 1, 1024 byte blocks<br>[ =C2=A0 1.439=
6132] sdmmc1 at sdhc0 slot 0<br>[ =C2=A0 1.4596145] usb0 at dwctwo0: USB re=
vision 2.0<br>[ =C2=A0 1.4696151] armpmu0: interrupting on local_intc irq 9=
<br>[ =C2=A0 1.4796185] uhub0 at usb0: NetBSD (0x0000) DWC2 root hub (0x000=
0), class 9/0, rev 2.00/1.00, addr 1<br>[ =C2=A0 1.5596215] sdmmc0: direct =
I/O error 5, r=3D6 p=3D0xffffc000b0fe3e5c write<br>[ =C2=A0 1.5696218] sdmm=
c0: couldn't enable card: 5<br>[ =C2=A0 1.6396270] sdmmc1: 4-bit width,=
50.000 MHz<br>[ =C2=A0 1.6496270] sdmmc1: SDIO function<br>[ =C2=A0 1.6496=
270] bwfm0 at sdmmc1 function 1<br>[ =C2=A0 1.6596295] (manufacturer 0x2d0,=
product 0xa9a6) at sdmmc1 function 2 not configured<br>[ =C2=A0 1.6696310]=
(manufacturer 0x2d0, product 0xa9a6, standard function interface code 0x2)=
at sdmmc1 function 3 not configured<br>[ =C2=A0 1.6807857] swwdog0: softwa=
re watchdog initialized<br>[ =C2=A0 1.6807857] WARNING: 3 errors while dete=
cting hardware; check system log.<br>[ =C2=A0 1.6896315] boot device: <u=
nknown><br>[ =C2=A0 1.6896315] unknown device major 0xffffffffffffffff<b=
r>[ =C2=A0 2.6896969] unknown device major 0xffffffffffffffff<br>[ =C2=A0 3=
.6897623] unknown device major 0xffffffffffffffff<br>[ =C2=A0 4.6898281] un=
known device major 0xffffffffffffffff<br>[ =C2=A0 5.6898932] unknown device=
major 0xffffffffffffffff<br>[ =C2=A0 6.6899576] unknown device major 0xfff=
fffffffffffff<br>[ =C2=A0 7.6900234] unknown device major 0xfffffffffffffff=
f<br>[ =C2=A0 8.6900887] unknown device major 0xffffffffffffffff<br>[ =C2=
=A0 9.6901540] unknown device major 0xffffffffffffffff<br>[ =C2=A010.690219=
6] unknown device major 0xffffffffffffffff<br>[ =C2=A011.6902858] unknown d=
evice major 0xffffffffffffffff<br>[ =C2=A012.6903514] unknown device major =
0xffffffffffffffff<br>[ =C2=A013.6904171] unknown device major 0xffffffffff=
ffffff<br>[ =C2=A014.6904828] unknown device major 0xffffffffffffffff<br>[ =
=C2=A015.6905485] unknown device major 0xffffffffffffffff<br>[ =C2=A016.690=
6144] unknown device major 0xffffffffffffffff<br>[ =C2=A017.6906794] unknow=
n device major 0xffffffffffffffff<br>[ =C2=A018.6907446] unknown device maj=
or 0xffffffffffffffff<br>[ =C2=A019.6908105] unknown device major 0xfffffff=
fffffffff<br>[ =C2=A020.6908759] unknown device major 0xffffffffffffffff<br=
>[ =C2=A021.6909417] unknown device major 0xffffffffffffffff<br>[ =C2=A021.=
7009432] root device:<br>[ =C2=A062.5036280] use one of: bwfm0 ddb halt reb=
oot<br>[ =C2=A062.5036280] root device: ddb<br>Stopped in pid 0.0 (system) =
at =C2=A0netbsd:cpu_Debugger+0xc: =C2=A0 =C2=A0 =C2=A0 =C2=A0ldp =C2=A0 =C2=
=A0 x29, x30<br>, [sp],#16<br>db{2}> set $lines =3D 0<br>$lines =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A018 =3D 0<br>db{2}> set $maxwidth =3D 0<br>$ma=
xwidth =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 50 =3D 0<br>db{2}&g=
t; show kernhist/i<br>kernhist 'usbhist': at 0xffffc00000d0e058 tot=
al 50000 next free 366<br>db{2}> show kernhist usbhist<br>000001.451787 =
usb_allocmem#1@1: called!<br>000001.451789 usb_allocmem#1@1: adding fragmen=
ts<br>000001.451791 usb_block_allocmem#1@1: called: size=3D8192 align=3D128=
flags=3D0x2<br>000001.462478 usb_match#1@1: called!<br>000001.466272 usb_d=
oattach#1@1: called!<br>000001.466282 usb_add_event#1@1: called!<br>000001.=
466285 usbd_new_device#1@1: called: bus=3D0xffff00003ac0b830 port=3D0 depth=
=3D0 speed=3D3<br>000001.466290 usbd_setup_pipe_flags#1@1: called: dev=3D0x=
ffff00003a984f00 addr=3D0 iface=3D0 ep=3D0xffff00003a984f38<br>000001.46629=
5 usbd_setup_pipe_flags#1@1: pipe=3D0xffff00003a918000<br>000001.466297 usb=
d_setup_pipe_flags#1@1: pipe=3D0xffff00003a918000<br>000001.466298 usbd_get=
_initial_ddesc#1@1: called: dev 0xffff00003a984f00<br>000001.466300 usbd_do=
_request_len#1@1: called: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa3c48 f=
lags=3D4 len=3D8<br>000001.466308 usbd_alloc_xfer#1@1: called: returns 0xff=
ff00003a981040<br>000001.466309 usb_allocmem#2@1: called!<br>000001.466312 =
usbd_transfer#1@1: called: xfer =3D 0xffff00003a981040, flags =3D 0x6, pipe=
=3D 0xffff00003a918000, running =3D 0<br>000001.466314 roothub_ctrl_start#=
1@1: called: type=3D0x80 request=3D0x6 len=3D0x8 value=3D0x100<br>000001.46=
6315 roothub_ctrl_start#1@1: wValue=3D0x100<br>000001.466318 roothub_ctrl_s=
tart#1@1: xfer 0xffff00003a981040 buflen 8 actlen 8 err 0<br>000001.466319 =
usb_transfer_complete#1@1: called: pipe =3D 0xffff00003a918000 xfer =3D 0xf=
fff00003a981040 status =3D 0 actlen =3D 8<br>000001.466320 usb_transfer_com=
plete#1@1: xfer 0xffff00003a981040: repeat 0 new head =3D 0<br>000001.46632=
1 usb_transfer_complete#1@1: xfer 0xffff00003a981040 doing done 0xffffc0000=
0240980<br>000001.466323 usb_transfer_complete#1@1: xfer 0xffff00003a981040=
doing callback 0 status 0<br>000001.466323 usb_transfer_complete#1@1: <=
- done xfer 0xffff00003a981040, wakeup<br>000001.466324 usbd_start_next#1@1=
: called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.466326 usbd_tra=
nsfer#1@1: <- done xfer 0xffff00003a981040, sync (err 0)<br>000001.46632=
7 usbd_free_xfer#1@1: called: 0xffff00003a981040<br>000001.466329 usb_freem=
em#1@1: called!<br>000001.466332 usb_rem_task_wait#1@1: called!<br>000001.4=
66339 usbd_new_device#1@1: adding unit addr=3D1, rev=3D200, class=3D9, subc=
lass=3D0<br>000001.466341 usbd_new_device#1@1: protocol=3D1, maxpacket=3D64=
, len=3D18, speed=3D3<br>000001.466346 usbd_ar_pipe#1@1: called: pipe =3D 0=
xffff00003a918000<br>000001.466348 usbd_close_pipe#1@1: called!<br>000001.4=
66349 usb_rem_task_wait#2@1: called!<br>000001.466352 usbd_setup_pipe_flags=
#2@1: called: dev=3D0xffff00003a984f00 addr=3D0 iface=3D0 ep=3D0xffff00003a=
984f38<br>000001.466353 usbd_setup_pipe_flags#2@1: pipe=3D0xffff00003a91800=
0<br>000001.466354 usbd_setup_pipe_flags#2@1: pipe=3D0xffff00003a918000<br>=
000001.466355 usbd_set_address#1@1: called: dev 0xffff00003a984f00 addr 1<b=
r>000001.466356 usbd_do_request_len#2@1: called: dev=3D0xffff00003a984f00 r=
eq=3Dffffc000b0fa3c88 flags=3D0 len=3D0<br>000001.466359 usbd_alloc_xfer#2@=
1: called: returns 0xffff00003a981040<br>000001.466359 usbd_transfer#2@1: c=
alled: xfer =3D 0xffff00003a981040, flags =3D 0x2, pipe =3D 0xffff00003a918=
000, running =3D 0<br>000001.466360 roothub_ctrl_start#2@1: called: type=3D=
0 request=3D0x5 len=3D0 value=3D0x1<br>000001.466361 roothub_ctrl_start#2@1=
: UR_SET_ADDRESS, UT_WRITE_DEVICE: addr 1<br>000001.466362 roothub_ctrl_sta=
rt#2@1: xfer 0xffff00003a981040 buflen 0 actlen 0 err 0<br>000001.466362 us=
b_transfer_complete#2@1: called: pipe =3D 0xffff00003a918000 xfer =3D 0xfff=
f00003a981040 status =3D 0 actlen =3D 0<br>000001.466363 usb_transfer_compl=
ete#2@1: xfer 0xffff00003a981040: repeat 0 new head =3D 0<br>000001.466363 =
usb_transfer_complete#2@1: xfer 0xffff00003a981040 doing done 0xffffc000002=
40980<br>000001.466364 usb_transfer_complete#2@1: xfer 0xffff00003a981040 d=
oing callback 0 status 0<br>000001.466365 usb_transfer_complete#2@1: <- =
done xfer 0xffff00003a981040, wakeup<br>000001.466365 usbd_start_next#2@1: =
called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.466366 usbd_trans=
fer#2@1: <- done xfer 0xffff00003a981040, sync (err 0)<br>000001.466366 =
usbd_free_xfer#2@1: called: 0xffff00003a981040<br>000001.466368 usb_rem_tas=
k_wait#3@1: called!<br>000001.476865 usb_task_thread#1@2: called: start tas=
kq 0xffffc0000113be68<br>000001.476871 usb_task_thread#2@2: called: start t=
askq 0xffffc0000113bea8<br>000001.484200 usbd_ar_pipe#2@2: called: pipe =3D=
0xffff00003a918000<br>000001.484201 usbd_close_pipe#2@2: called!<br>000001=
.484202 usb_rem_task_wait#4@2: called!<br>000001.484204 usbd_setup_pipe_fla=
gs#3@2: called: dev=3D0xffff00003a984f00 addr=3D1 iface=3D0 ep=3D0xffff0000=
3a984f38<br>000001.484205 usbd_setup_pipe_flags#3@2: pipe=3D0xffff00003a918=
000<br>000001.484207 usbd_setup_pipe_flags#3@2: pipe=3D0xffff00003a918000<b=
r>000001.484209 usbd_reload_device_desc#1@2: called!<br>000001.484210 usbd_=
get_device_desc#1@2: called!<br>000001.484212 usbd_get_desc#1@2: called: ty=
pe=3D1, index=3D0, len=3D18<br>000001.484212 usbd_do_request_len#3@2: calle=
d: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa3c28 flags=3D0 len=3D12<br>00=
0001.484218 usbd_alloc_xfer#3@2: called: returns 0xffff00003a981190<br>0000=
01.484219 usb_allocmem#3@2: called!<br>000001.484221 usbd_transfer#3@2: cal=
led: xfer =3D 0xffff00003a981190, flags =3D 0x2, pipe =3D 0xffff00003a91800=
0, running =3D 0<br>000001.484222 roothub_ctrl_start#3@2: called: type=3D0x=
80 request=3D0x6 len=3D0x12 value=3D0x100<br>000001.484223 roothub_ctrl_sta=
rt#3@2: wValue=3D0x100<br>000001.484224 roothub_ctrl_start#3@2: xfer 0xffff=
00003a981190 buflen 18 actlen 18 err 0<br>000001.484225 usb_transfer_comple=
te#3@2: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00003a981190 sta=
tus =3D 0 actlen =3D 18<br>000001.484226 usb_transfer_complete#3@2: xfer 0x=
ffff00003a981190: repeat 0 new head =3D 0<br>000001.484226 usb_transfer_com=
plete#3@2: xfer 0xffff00003a981190 doing done 0xffffc00000240980<br>000001.=
484227 usb_transfer_complete#3@2: xfer 0xffff00003a981190 doing callback 0 =
status 0<br>000001.484228 usb_transfer_complete#3@2: <- done xfer 0xffff=
00003a981190, wakeup<br>000001.484229 usbd_start_next#3@2: called: pipe =3D=
0xffff00003a918000, xfer =3D 0<br>000001.484229 usbd_transfer#3@2: <- d=
one xfer 0xffff00003a981190, sync (err 0)<br>000001.484230 usbd_free_xfer#3=
@2: called: 0xffff00003a981190<br>000001.484231 usb_freemem#2@2: called!<br=
>000001.484233 usb_rem_task_wait#5@2: called!<br>000001.484240 usbd_new_dev=
ice#1@2: new dev (addr 1), dev=3D0xffff00003a984f00, parent=3D0xffff00003a9=
4c400<br>000001.484244 usbd_get_string0#1@2: called!<br>000001.484245 usbd_=
get_string_desc#1@2: called!<br>000001.484246 usbd_do_request_len#4@2: call=
ed: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe<br>0=
00001.484248 usbd_alloc_xfer#4@2: called: returns 0xffff00003a981190<br>000=
001.484249 usb_allocmem#4@2: called!<br>000001.484250 usb_allocmem#4@2: lar=
ge alloc 254<br>000001.484250 usb_block_allocmem#2@2: called: size=3D8192 a=
lign=3D0 flags=3D0<br>000001.484273 usbd_transfer#4@2: called: xfer =3D 0xf=
fff00003a981190, flags =3D 0x6, pipe =3D 0xffff00003a918000, running =3D 0<=
br>000001.484274 roothub_ctrl_start#4@2: called: type=3D0x80 request=3D0x6 =
len=3D0x2 value=3D0x300<br>000001.484275 roothub_ctrl_start#4@2: wValue=3D0=
x300<br>000001.484276 roothub_ctrl_start#4@2: xfer 0xffff00003a981190 bufle=
n 2 actlen 2 err 0<br>000001.484277 usb_transfer_complete#4@2: called: pipe=
=3D 0xffff00003a918000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D=
2<br>000001.484277 usb_transfer_complete#4@2: xfer 0xffff00003a981190: rep=
eat 0 new head =3D 0<br>000001.484278 usb_transfer_complete#4@2: xfer 0xfff=
f00003a981190 doing done 0xffffc00000240980<br>000001.484278 usb_transfer_c=
omplete#4@2: xfer 0xffff00003a981190 doing callback 0 status 0<br>000001.48=
4279 usb_transfer_complete#4@2: <- done xfer 0xffff00003a981190, wakeup<=
br>000001.484279 usbd_start_next#4@2: called: pipe =3D 0xffff00003a918000, =
xfer =3D 0<br>000001.484280 usbd_transfer#4@2: <- done xfer 0xffff00003a=
981190, sync (err 0)<br>000001.484281 usbd_free_xfer#4@2: called: 0xffff000=
03a981190<br>000001.484281 usb_freemem#3@2: called!<br>000001.484282 usb_fr=
eemem#3@2: large free<br>000001.484283 usb_block_freemem#1@2: called: size=
=3D8192<br>000001.484284 usb_rem_task_wait#6@2: called!<br>000001.484287 us=
bd_do_request_len#5@2: called: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa3=
ad8 flags=3D4 len=3Dfe<br>000001.484290 usbd_alloc_xfer#5@2: called: return=
s 0xffff00003a981190<br>000001.484290 usb_allocmem#5@2: called!<br>000001.4=
84291 usb_allocmem#5@2: large alloc 254<br>000001.484292 usb_block_allocmem=
#3@2: called: size=3D8192 align=3D0 flags=3D0<br>000001.484293 usbd_transfe=
r#5@2: called: xfer =3D 0xffff00003a981190, flags =3D 0x6, pipe =3D 0xffff0=
0003a918000, running =3D 0<br>000001.484293 roothub_ctrl_start#5@2: called:=
type=3D0x80 request=3D0x6 len=3D0x4 value=3D0x300<br>000001.484294 roothub=
_ctrl_start#5@2: wValue=3D0x300<br>000001.484295 roothub_ctrl_start#5@2: xf=
er 0xffff00003a981190 buflen 4 actlen 4 err 0<br>000001.484295 usb_transfer=
_complete#5@2: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00003a981=
190 status =3D 0 actlen =3D 4<br>000001.484296 usb_transfer_complete#5@2: x=
fer 0xffff00003a981190: repeat 0 new head =3D 0<br>000001.484297 usb_transf=
er_complete#5@2: xfer 0xffff00003a981190 doing done 0xffffc00000240980<br>0=
00001.484297 usb_transfer_complete#5@2: xfer 0xffff00003a981190 doing callb=
ack 0 status 0<br>000001.484298 usb_transfer_complete#5@2: <- done xfer =
0xffff00003a981190, wakeup<br>000001.484298 usbd_start_next#5@2: called: pi=
pe =3D 0xffff00003a918000, xfer =3D 0<br>000001.484299 usbd_transfer#5@2: &=
lt;- done xfer 0xffff00003a981190, sync (err 0)<br>000001.484300 usbd_free_=
xfer#5@2: called: 0xffff00003a981190<br>000001.484300 usb_freemem#4@2: call=
ed!<br>000001.484301 usb_freemem#4@2: large free<br>000001.484302 usb_block=
_freemem#2@2: called: size=3D8192<br>000001.484303 usb_rem_task_wait#7@2: c=
alled!<br>000001.484305 usbd_get_string_desc#2@2: called!<br>000001.484306 =
usbd_do_request_len#6@2: called: dev=3D0xffff00003a984f00 req=3Dffffc000b0f=
a3ad8 flags=3D4 len=3Dfe<br>000001.484309 usbd_alloc_xfer#6@2: called: retu=
rns 0xffff00003a981190<br>000001.484309 usb_allocmem#6@2: called!<br>000001=
.484310 usb_allocmem#6@2: large alloc 254<br>000001.484310 usb_block_allocm=
em#4@2: called: size=3D8192 align=3D0 flags=3D0<br>000001.484311 usbd_trans=
fer#6@2: called: xfer =3D 0xffff00003a981190, flags =3D 0x6, pipe =3D 0xfff=
f00003a918000, running =3D 0<br>000001.484312 roothub_ctrl_start#6@2: calle=
d: type=3D0x80 request=3D0x6 len=3D0x2 value=3D0x301<br>000001.484313 rooth=
ub_ctrl_start#6@2: wValue=3D0x301<br>000001.484314 roothub_ctrl_start#6@2: =
xfer 0xffff00003a981190 buflen 2 actlen 2 err 0<br>000001.484314 usb_transf=
er_complete#6@2: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00003a9=
81190 status =3D 0 actlen =3D 2<br>000001.484315 usb_transfer_complete#6@2:=
xfer 0xffff00003a981190: repeat 0 new head =3D 0<br>000001.484315 usb_tran=
sfer_complete#6@2: xfer 0xffff00003a981190 doing done 0xffffc00000240980<br=
>000001.484316 usb_transfer_complete#6@2: xfer 0xffff00003a981190 doing cal=
lback 0 status 0<br>000001.484317 usb_transfer_complete#6@2: <- done xfe=
r 0xffff00003a981190, wakeup<br>000001.484317 usbd_start_next#6@2: called: =
pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.484318 usbd_transfer#6@2:=
<- done xfer 0xffff00003a981190, sync (err 0)<br>000001.484318 usbd_fre=
e_xfer#6@2: called: 0xffff00003a981190<br>000001.484319 usb_freemem#5@2: ca=
lled!<br>000001.484320 usb_freemem#5@2: large free<br>000001.484320 usb_blo=
ck_freemem#3@2: called: size=3D8192<br>000001.484321 usb_rem_task_wait#8@2:=
called!<br>000001.484324 usbd_do_request_len#7@2: called: dev=3D0xffff0000=
3a984f00 req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe<br>000001.484326 usbd_al=
loc_xfer#7@2: called: returns 0xffff00003a981190<br>000001.484327 usb_alloc=
mem#7@2: called!<br>000001.484327 usb_allocmem#7@2: large alloc 254<br>0000=
01.484328 usb_block_allocmem#5@2: called: size=3D8192 align=3D0 flags=3D0<b=
r>000001.484329 usbd_transfer#7@2: called: xfer =3D 0xffff00003a981190, fla=
gs =3D 0x6, pipe =3D 0xffff00003a918000, running =3D 0<br>000001.484329 roo=
thub_ctrl_start#7@2: called: type=3D0x80 request=3D0x6 len=3D0xe value=3D0x=
301<br>000001.484330 roothub_ctrl_start#7@2: wValue=3D0x301<br>000001.48433=
1 roothub_ctrl_start#7@2: xfer 0xffff00003a981190 buflen 14 actlen 14 err 0=
<br>000001.484331 usb_transfer_complete#7@2: called: pipe =3D 0xffff00003a9=
18000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 14<br>000001.4843=
32 usb_transfer_complete#7@2: xfer 0xffff00003a981190: repeat 0 new head =
=3D 0<br>000001.484332 usb_transfer_complete#7@2: xfer 0xffff00003a981190 d=
oing done 0xffffc00000240980<br>000001.484333 usb_transfer_complete#7@2: xf=
er 0xffff00003a981190 doing callback 0 status 0<br>000001.484334 usb_transf=
er_complete#7@2: <- done xfer 0xffff00003a981190, wakeup<br>000001.48433=
4 usbd_start_next#7@2: called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>0=
00001.484335 usbd_transfer#7@2: <- done xfer 0xffff00003a981190, sync (e=
rr 0)<br>000001.484335 usbd_free_xfer#7@2: called: 0xffff00003a981190<br>00=
0001.484336 usb_freemem#6@2: called!<br>000001.484337 usb_freemem#6@2: larg=
e free<br>000001.484337 usb_block_freemem#4@2: called: size=3D8192<br>00000=
1.484338 usb_rem_task_wait#9@2: called!<br>000001.484343 usbd_get_string0#2=
@2: called!<br>000001.484344 usbd_get_string_desc#3@2: called!<br>000001.48=
4344 usbd_do_request_len#8@2: called: dev=3D0xffff00003a984f00 req=3Dffffc0=
00b0fa3ad8 flags=3D4 len=3Dfe<br>000001.484347 usbd_alloc_xfer#8@2: called:=
returns 0xffff00003a981190<br>000001.484348 usb_allocmem#8@2: called!<br>0=
00001.484348 usb_allocmem#8@2: large alloc 254<br>000001.484349 usb_block_a=
llocmem#6@2: called: size=3D8192 align=3D0 flags=3D0<br>000001.484350 usbd_=
transfer#8@2: called: xfer =3D 0xffff00003a981190, flags =3D 0x6, pipe =3D =
0xffff00003a918000, running =3D 0<br>000001.484350 roothub_ctrl_start#8@2: =
called: type=3D0x80 request=3D0x6 len=3D0x2 value=3D0x302<br>000001.484351 =
roothub_ctrl_start#8@2: wValue=3D0x302<br>000001.484352 roothub_ctrl_start#=
8@2: xfer 0xffff00003a981190 buflen 2 actlen 2 err 0<br>000001.484353 usb_t=
ransfer_complete#8@2: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00=
003a981190 status =3D 0 actlen =3D 2<br>000001.484353 usb_transfer_complete=
#8@2: xfer 0xffff00003a981190: repeat 0 new head =3D 0<br>000001.484354 usb=
_transfer_complete#8@2: xfer 0xffff00003a981190 doing done 0xffffc000002409=
80<br>000001.484355 usb_transfer_complete#8@2: xfer 0xffff00003a981190 doin=
g callback 0 status 0<br>000001.484355 usb_transfer_complete#8@2: <- don=
e xfer 0xffff00003a981190, wakeup<br>000001.484356 usbd_start_next#8@2: cal=
led: pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.484356 usbd_transfer=
#8@2: <- done xfer 0xffff00003a981190, sync (err 0)<br>000001.484357 usb=
d_free_xfer#8@2: called: 0xffff00003a981190<br>000001.484358 usb_freemem#7@=
2: called!<br>000001.484358 usb_freemem#7@2: large free<br>000001.484359 us=
b_block_freemem#5@2: called: size=3D8192<br>000001.484360 usb_rem_task_wait=
#10@2: called!<br>000001.484363 usbd_do_request_len#9@2: called: dev=3D0xff=
ff00003a984f00 req=3Dffffc000b0fa3ad8 flags=3D4 len=3Dfe<br>000001.484365 u=
sbd_alloc_xfer#9@2: called: returns 0xffff00003a981190<br>000001.484365 usb=
_allocmem#9@2: called!<br>000001.484366 usb_allocmem#9@2: large alloc 254<b=
r>000001.484367 usb_block_allocmem#7@2: called: size=3D8192 align=3D0 flags=
=3D0<br>000001.484367 usbd_transfer#9@2: called: xfer =3D 0xffff00003a98119=
0, flags =3D 0x6, pipe =3D 0xffff00003a918000, running =3D 0<br>000001.4843=
68 roothub_ctrl_start#9@2: called: type=3D0x80 request=3D0x6 len=3D0x1c val=
ue=3D0x302<br>000001.484368 roothub_ctrl_start#9@2: wValue=3D0x302<br>00000=
1.484370 roothub_ctrl_start#9@2: xfer 0xffff00003a981190 buflen 18 actlen 2=
8 err 0<br>000001.484370 usb_transfer_complete#9@2: called: pipe =3D 0xffff=
00003a918000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 28<br>0000=
01.484371 usb_transfer_complete#9@2: xfer 0xffff00003a981190: repeat 0 new =
head =3D 0<br>000001.484372 usb_transfer_complete#9@2: xfer 0xffff00003a981=
190 doing done 0xffffc00000240980<br>000001.484372 usb_transfer_complete#9@=
2: xfer 0xffff00003a981190 doing callback 0 status 0<br>000001.484373 usb_t=
ransfer_complete#9@2: <- done xfer 0xffff00003a981190, wakeup<br>000001.=
484373 usbd_start_next#9@2: called: pipe =3D 0xffff00003a918000, xfer =3D 0=
<br>000001.484374 usbd_transfer#9@2: <- done xfer 0xffff00003a981190, sy=
nc (err 0)<br>000001.484375 usbd_free_xfer#9@2: called: 0xffff00003a981190<=
br>000001.484375 usb_freemem#8@2: called!<br>000001.484376 usb_freemem#8@2:=
large free<br>000001.484376 usb_block_freemem#6@2: called: size=3D8192<br>=
000001.484378 usb_rem_task_wait#11@2: called!<br>000001.484385 usbd_get_str=
ing0#3@2: called!<br>000001.484409 usb_add_event#2@2: called!<br>000001.492=
995 usbd_set_config_index#1@2: called: dev=3D0xffff00003a984f00 index=3D0<b=
r>000001.492997 usbd_get_config_desc#1@2: called: confidx=3D0<br>000001.492=
998 usbd_get_desc#2@2: called: type=3D2, index=3D0, len=3D9<br>000001.49299=
8 usbd_do_request_len#10@2: called: dev=3D0xffff00003a984f00 req=3Dffffc000=
b0fa3978 flags=3D0 len=3D9<br>000001.493003 usbd_alloc_xfer#10@2: called: r=
eturns 0xffff00003a981190<br>000001.493003 usb_allocmem#10@2: called!<br>00=
0001.493006 usbd_transfer#10@2: called: xfer =3D 0xffff00003a981190, flags =
=3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0<br>000001.493007 roothu=
b_ctrl_start#10@2: called: type=3D0x80 request=3D0x6 len=3D0x9 value=3D0x20=
0<br>000001.493007 roothub_ctrl_start#10@2: wValue=3D0x200<br>000001.493008=
roothub_ctrl_start#10@2: xfer 0xffff00003a981190 buflen 9 actlen 9 err 0<b=
r>000001.493009 usb_transfer_complete#10@2: called: pipe =3D 0xffff00003a91=
8000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 9<br>000001.493009=
usb_transfer_complete#10@2: xfer 0xffff00003a981190: repeat 0 new head =3D=
0<br>000001.493010 usb_transfer_complete#10@2: xfer 0xffff00003a981190 doi=
ng done 0xffffc00000240980<br>000001.493011 usb_transfer_complete#10@2: xfe=
r 0xffff00003a981190 doing callback 0 status 0<br>000001.493011 usb_transfe=
r_complete#10@2: <- done xfer 0xffff00003a981190, wakeup<br>000001.49301=
2 usbd_start_next#10@2: called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>=
000001.493013 usbd_transfer#10@2: <- done xfer 0xffff00003a981190, sync =
(err 0)<br>000001.493013 usbd_free_xfer#10@2: called: 0xffff00003a981190<br=
>000001.493014 usb_freemem#9@2: called!<br>000001.493015 usb_rem_task_wait#=
12@2: called!<br>000001.493019 usbd_get_desc#3@2: called: type=3D2, index=
=3D0, len=3D25<br>000001.493019 usbd_do_request_len#11@2: called: dev=3D0xf=
fff00003a984f00 req=3Dffffc000b0fa39c8 flags=3D0 len=3D19<br>000001.493022 =
usbd_alloc_xfer#11@2: called: returns 0xffff00003a981190<br>000001.493022 u=
sb_allocmem#11@2: called!<br>000001.493024 usbd_transfer#11@2: called: xfer=
=3D 0xffff00003a981190, flags =3D 0x2, pipe =3D 0xffff00003a918000, runnin=
g =3D 0<br>000001.493025 roothub_ctrl_start#11@2: called: type=3D0x80 reque=
st=3D0x6 len=3D0x19 value=3D0x200<br>000001.493026 roothub_ctrl_start#11@2:=
wValue=3D0x200<br>000001.493026 roothub_ctrl_start#11@2: xfer 0xffff00003a=
981190 buflen 25 actlen 25 err 0<br>000001.493027 usb_transfer_complete#11@=
2: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00003a981190 status =
=3D 0 actlen =3D 25<br>000001.493028 usb_transfer_complete#11@2: xfer 0xfff=
f00003a981190: repeat 0 new head =3D 0<br>000001.493028 usb_transfer_comple=
te#11@2: xfer 0xffff00003a981190 doing done 0xffffc00000240980<br>000001.49=
3029 usb_transfer_complete#11@2: xfer 0xffff00003a981190 doing callback 0 s=
tatus 0<br>000001.493030 usb_transfer_complete#11@2: <- done xfer 0xffff=
00003a981190, wakeup<br>000001.493030 usbd_start_next#11@2: called: pipe =
=3D 0xffff00003a918000, xfer =3D 0<br>000001.493031 usbd_transfer#11@2: <=
;- done xfer 0xffff00003a981190, sync (err 0)<br>000001.493033 usbd_free_xf=
er#11@2: called: 0xffff00003a981190<br>000001.493034 usb_freemem#10@2: call=
ed!<br>000001.493037 usb_rem_task_wait#13@2: called!<br>000001.493041 usbd_=
set_config_index#1@2: addr 1 cno=3D1 attr=3D0xc0, selfpowered=3D1<br>000001=
.493041 usbd_set_config_index#1@2: max power=3D0<br>000001.493042 usbd_set_=
config_index#1@2: set config 1<br>000001.493043 usbd_set_config#1@2: called=
: dev 0xffff00003a984f00 conf 1<br>000001.493044 usbd_do_request_len#12@2: =
called: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa39c8 flags=3D0 len=3D0<b=
r>000001.493046 usbd_alloc_xfer#12@2: called: returns 0xffff00003a981190<br=
>000001.493047 usbd_transfer#12@2: called: xfer =3D 0xffff00003a981190, fla=
gs =3D 0x2, pipe =3D 0xffff00003a918000, running =3D 0<br>000001.493048 roo=
thub_ctrl_start#12@2: called: type=3D0 request=3D0x9 len=3D0 value=3D0x1<br=
>000001.493048 roothub_ctrl_start#12@2: xfer 0xffff00003a981190 buflen 0 ac=
tlen 0 err 0<br>000001.493049 usb_transfer_complete#12@2: called: pipe =3D =
0xffff00003a918000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 0<br=
>000001.493049 usb_transfer_complete#12@2: xfer 0xffff00003a981190: repeat =
0 new head =3D 0<br>000001.493050 usb_transfer_complete#12@2: xfer 0xffff00=
003a981190 doing done 0xffffc00000240980<br>000001.493050 usb_transfer_comp=
lete#12@2: xfer 0xffff00003a981190 doing callback 0 status 0<br>000001.4930=
51 usb_transfer_complete#12@2: <- done xfer 0xffff00003a981190, wakeup<b=
r>000001.493052 usbd_start_next#12@2: called: pipe =3D 0xffff00003a918000, =
xfer =3D 0<br>000001.493052 usbd_transfer#12@2: <- done xfer 0xffff00003=
a981190, sync (err 0)<br>000001.493053 usbd_free_xfer#12@2: called: 0xffff0=
0003a981190<br>000001.493054 usb_rem_task_wait#14@2: called!<br>000001.4930=
59 usbd_fill_iface_data#1@2: called: ifaceidx=3D0 altidx=3D0<br>000001.4930=
60 usbd_find_idesc#1@2: called: iface/alt idx 0/0<br>000001.493064 usbd_do_=
request_len#13@2: called: dev=3D0xffff00003a984f00 req=3Dffffc000b0fa3ad0 f=
lags=3D0 len=3D9<br>000001.493066 usbd_alloc_xfer#13@2: called: returns 0xf=
fff00003a981190<br>000001.493067 usb_allocmem#12@2: called!<br>000001.49306=
9 usbd_transfer#13@2: called: xfer =3D 0xffff00003a981190, flags =3D 0x2, p=
ipe =3D 0xffff00003a918000, running =3D 0<br>000001.493070 roothub_ctrl_sta=
rt#13@2: called: type=3D0xa0 request=3D0x6 len=3D0x9 value=3D0x2900<br>0000=
01.493071 roothub_ctrl_start#13@2: xfer 0xffff00003a981190 buflen 9 actlen =
9 err 0<br>000001.493072 usb_transfer_complete#13@2: called: pipe =3D 0xfff=
f00003a918000 xfer =3D 0xffff00003a981190 status =3D 0 actlen =3D 9<br>0000=
01.493072 usb_transfer_complete#13@2: xfer 0xffff00003a981190: repeat 0 new=
head =3D 0<br>000001.493073 usb_transfer_complete#13@2: xfer 0xffff00003a9=
81190 doing done 0xffffc00000240980<br>000001.493074 usb_transfer_complete#=
13@2: xfer 0xffff00003a981190 doing callback 0 status 0<br>000001.493074 us=
b_transfer_complete#13@2: <- done xfer 0xffff00003a981190, wakeup<br>000=
001.493075 usbd_start_next#13@2: called: pipe =3D 0xffff00003a918000, xfer =
=3D 0<br>000001.493075 usbd_transfer#13@2: <- done xfer 0xffff00003a9811=
90, sync (err 0)<br>000001.493076 usbd_free_xfer#13@2: called: 0xffff00003a=
981190<br>000001.493077 usb_freemem#11@2: called!<br>000001.493078 usb_rem_=
task_wait#15@2: called!<br>000001.493122 usbd_open_pipe_intr#1@2: called: a=
ddress =3D 0x81 flags =3D 0x84 len =3D 1<br>000001.493123 usbd_open_pipe_iv=
al#1@2: called: iface =3D 0xffff00003aaed8c0 address =3D 0x81 flags =3D 0x8=
1<br>000001.493125 usbd_setup_pipe_flags#4@2: called: dev=3D0xffff00003a984=
f00 addr=3D1 iface=3D0xffff00003aaed8c0 ep=3D0xffff00003afde3b0<br>000001.4=
93127 usbd_setup_pipe_flags#4@2: pipe=3D0xffff00003a918700<br>000001.493128=
usbd_setup_pipe_flags#4@2: pipe=3D0xffff00003a918700<br>000001.493132 usbd=
_alloc_xfer#14@2: called: returns 0xffff00003a981190<br>000001.493132 usb_a=
llocmem#13@2: called!<br>000001.493135 usbd_transfer#14@2: called: xfer =3D=
0xffff00003a981190, flags =3D 0x84, pipe =3D 0xffff00003a918700, running =
=3D 0<br>000001.493136 usbd_transfer#14@2: <- done xfer 0xffff00003a9811=
90, not sync (err 1)<br>000001.493144 usb_add_event#3@2: called!<br>000001.=
493148 usbd_set_port_feature#1@2: called: dev 0xffff00003a984f00 port 8 sel=
<br>000001.493148 usbd_do_request_len#14@2: called: dev=3D0xffff00003a984f0=
0 req=3Dffffc000b0fa3a68 flags=3D0 len=3D0<br>000001.493153 usbd_alloc_xfer=
#15@2: called: returns 0xffff00003a9812e0<br>000001.493154 usbd_transfer#15=
@2: called: xfer =3D 0xffff00003a9812e0, flags =3D 0x2, pipe =3D 0xffff0000=
3a918000, running =3D 0<br>000001.493155 roothub_ctrl_start#14@2: called: t=
ype=3D0x23 request=3D0x3 len=3D0 value=3D0x8<br>000001.493155 roothub_ctrl_=
start#14@2: xfer 0xffff00003a9812e0 buflen -1 actlen 0 err 0<br>000001.4931=
56 usb_transfer_complete#14@2: called: pipe =3D 0xffff00003a918000 xfer =3D=
0xffff00003a9812e0 status =3D 0 actlen =3D 0<br>000001.493157 usb_transfer=
_complete#14@2: xfer 0xffff00003a9812e0: repeat 0 new head =3D 0<br>000001.=
493157 usb_transfer_complete#14@2: xfer 0xffff00003a9812e0 doing done 0xfff=
fc00000240980<br>000001.493158 usb_transfer_complete#14@2: xfer 0xffff00003=
a982e0 doing callback 0 status 0<br>000001.493159 usb_transfer_complete#14@=
2: <- done xfer 0xffff00003a9812e0, wakeup<br>000001.493161 usbd_start_n=
ext#14@2: called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.493162 =
usbd_transfer#15@2: <- done xfer 0xffff00003a9812e0, sync (err 0)<br>000=
001.493163 usbd_free_xfer#14@2: called: 0xffff00003a9812e0<br>000001.493165=
usb_rem_task_wait#16@2: called!<br>000001.493195 usb_event_thread#1@0: cal=
led!<br>000001.493197 usb_discover#1@0: called!<br>000001.493199 usbd_get_h=
ub_status#1@0: called: dev 0xffff00003a984f00<br>000001.493200 usbd_do_requ=
est_len#15@0: called: dev=3D0xffff00003a984f00 req=3Dffffc000b0fbbd78 flags=
=3D0 len=3D4<br>000001.493207 usbd_alloc_xfer#16@0: called: returns 0xffff0=
0003a981430<br>000001.493207 usb_allocmem#14@0: called!<br>000001.493210 us=
bd_transfer#16@0: called: xfer =3D 0xffff00003a981430, flags =3D 0x2, pipe =
=3D 0xffff00003a918000, running =3D 0<br>000001.493211 roothub_ctrl_start#1=
5@0: called: type=3D0xa0 request=3D0 len=3D0x4 value=3D0<br>000001.493212 r=
oothub_ctrl_start#15@0: xfer 0xffff00003a981430 buflen -1 actlen 4 err 0<br=
>000001.493213 usb_transfer_complete#15@0: called: pipe =3D 0xffff00003a918=
000 xfer =3D 0xffff00003a981430 status =3D 0 actlen =3D 4<br>000001.493213 =
usb_transfer_complete#15@0: xfer 0xffff00003a981430: repeat 0 new head =3D =
0<br>000001.493214 usb_transfer_complete#15@0: xfer 0xffff00003a981430 doin=
g done 0xffffc00000240980<br>000001.493215 usb_transfer_complete#15@0: xfer=
0xffff00003a981430 dong callback 0 status 0<br>000001.493215 usb_transfer_=
complete#15@0: <- done xfer 0xffff00003a981430, wakeup<br>000001.493216 =
usbd_start_next#15@0: called: pipe =3D 0xffff00003a918000, xfer =3D 0<br>00=
0001.493217 usbd_transfer#16@0: <- done xfer 0xffff00003a981430, sync (e=
rr 0)<br>000001.493218 usbd_free_xfer#15@0: called: 0xffff00003a981430<br>0=
00001.493218 usb_freemem#12@0: called!<br>000001.493220 usb_rem_task_wait#1=
7@0: called!<br>000001.493229 usbd_get_port_status#1@0: called: dev 0xffff0=
0003a984f00 port 1<br>000001.493230 usbd_do_request_len#16@0: called: dev=
=3D0xffff00003a984f00 req=3Dffffc000b0fbbd78 flags=3D0 len=3D4<br>000001.49=
3233 usbd_alloc_xfer#17@0: called: returns 0xffff00003a981430<br>000001.493=
233 usb_allocmem#15@0: called!<br>000001.493235 usbd_transfer#17@0: called:=
xfer =3D 0xffff00003a981430, flags =3D 0x2, pipe =3D 0xffff00003a918000, r=
unning =3D 0<br>000001.493236 roothub_ctrl_start#16@0: called: type=3D0xa3 =
request=3D0 len=3D0x4 value=3D0<br>000001.493237 roothub_ctrl_start#16@0: x=
fer 0xffff00003a981430 buflen -1 actlen 4 err 0<br>00000.493237 usb_transfe=
r_complete#16@0: called: pipe =3D 0xffff00003a918000 xfer =3D 0xffff00003a9=
81430 status =3D 0 actlen =3D 4<br>000001.493238 usb_transfer_complete#16@0=
: xfer 0xffff00003a981430: repeat 0 new head =3D 0<br>000001.493239 usb_tra=
nsfer_complete#16@0: xfer 0xffff00003a981430 doing done 0xffffc00000240980<=
br>000001.493240 usb_transfer_complete#16@0: xfer 0xffff00003a981430 doing =
callback 0 stats 0<br>000001.493241 usb_transfer_complete#16@0: <- done =
xfer 0xffff00003a981430, wakeup<br>000001.493241 usbd_start_next#16@0: call=
ed: pipe =3D 0xffff00003a918000, xfer =3D 0<br>000001.493242 usbd_transfer#=
17@0: <- done xfer 0xffff00003a981430, sync (err 0)<br>000001.493242 usb=
d_free_xfer#16@0: called: 0xffff00003a981430<br>000001.493243 usb_freemem#1=
3@0: called!<br>000001.493245 usb_rem_task_wait#18@0: called!<br>000001.493=
249 usb_discover#2@0: called!<br>000061.493583 usb_discover#3@0: called!<br=
>000121.497526 usb_discover#4@0: called!<br>000181.501472 usb_discover#5@0:=
called!<br>000241.505422 usb_discover#6@0: called!<br>000301.509371 usb_di=
scover#7@0: called!<br>000361.513318 usb_discover#8@0: called!<br>000421.51=
7263 usb_discover#9@0: called!<br>000481.521199 usb_discover#10@0: called!<=
br>000541.525142 usb_discover#11@0: called!<br>000601.529086 usb_discover#1=
2@0: called!<br>000661.533028 usb_discover#13@0: called!<br>000721.536973 u=
sb_discover#14@0: called!<br>000781.540918 usb_discover#15@0: called!<br>00=
0841.544863 usb_discover#16@0: called!<br>000901.548806 usb_discover#17@0: =
called!<br>000961.552748 usb_discover#18@0: called!<br>db{2}><br><br>On =
Tue, Aug 4, 2026 at 11:35=E2=80=AFAM Nick Hudson via gnats <<a href=3D"m=
ailto:gnats-admin%netbsd.org@localhost">gnats-admin%netbsd.org@localhost</a>> wrote:<br>>=
<br>> The following reply was made to PR port-arm/60021; it has been not=
ed by GNATS.<br>><br>> From: Nick Hudson <<a href=3D"mailto:nick.h=
udson%gmx.co.uk@localhost">nick.hudson%gmx.co.uk@localhost</a>><br>> To: Taylor R Campbel=
l <riastradh%NetBSD.org@localhost><br>> Cc: <a href=3D"mailto:mac%culver.net@localhost=
">mac%culver.net@localhost</a>,<br>> =C2=A0"<a href=3D"mailto:gnats-bugs@netb=
sd.org">gnats-bugs%netbsd.org@localhost</a>" <gnats-bugs%NetBSD.org@localhost>,<br>&=
gt; =C2=A0"<a href=3D"mailto:netbsd-bugs%netbsd.org@localhost";>netbsd-bugs@netbs=
d.org</a>" <netbsd-bugs%NetBSD.org@localhost><br>> Subject: Re: port-ar=
m/60021: USB-only boot: uhub0 attaches but uhub1 never<br>> =C2=A0appear=
s, no hotplug events; SD-boot sees hub+umass fine<br>> Date: Tue, 4 Aug =
2026 19:32:12 +0100<br>><br>> =C2=A0> On 4 Aug 2026, at 14:34, Tay=
lor R Campbell <riastradh%NetBSD.org@localhost> =3D<br>> =C2=A0wrote:<br>>=
; =C2=A0>=3D20<br>> =C2=A0>> Date: Sat, 21 Feb 2026 10:39:41 +0=
000<br>> =C2=A0>> From: Nick Hudson <<a href=3D"mailto:nick.hud=
son%gmx.co.uk@localhost">nick.hudson%gmx.co.uk@localhost</a>><br>> =C2=A0>>=3D20<br=
>> =C2=A0>> This is almost certainly that autoconf doesn't wai=
t (long enough) for<br>> =C2=A0>> sub-ordintate hubs<br>> =C2=
=A0>>=3D20<br>> =C2=A0>> <a href=3D"https://nxr.netbsd.org/x=
ref/src/sys/dev/usb/uhub.c#880">https://nxr.netbsd.org/xref/src/sys/dev/usb=
/uhub.c#880</a><br>> =C2=A0>>=3D20<br>> =C2=A0>> =C2=A0 =
=C2=A0 880 mutex_enter(&sc->sc_lock);<br>> =C2=A0>> =C2=A0 =
=C2=A0 881 sc->sc_explorepending =3D3D false;<br>> =C2=A0>> =C2=
=A0 =C2=A0 882 for (int i =3D3D 0; i < sc->sc_statuslen; i++) {<br>&g=
t; =C2=A0>> =C2=A0 =C2=A0 883 if (sc->sc_statuspend[i] !=3D3D 0) {=
<br>> =C2=A0>> =C2=A0 =C2=A0 884 memcpy(sc->sc_status, sc->s=
c_statuspend,<br>> =C2=A0>> =C2=A0 =C2=A0 885 =C2=A0 =C2=A0sc->=
sc_statuslen);<br>> =C2=A0>> =C2=A0 =C2=A0 886 memset(sc->sc_st=
atuspend, 0, sc->sc_statuslen);<br>> =C2=A0>> =C2=A0 =C2=A0 887=
usb_needs_explore(sc->sc_hub);<br>> =C2=A0>> =C2=A0 =C2=A0 888=
break;<br>> =C2=A0>> =C2=A0 =C2=A0 889 }<br>> =C2=A0>> =
=C2=A0 =C2=A0 890 }<br>> =C2=A0>> =C2=A0 =C2=A0 891 mutex_exit(&am=
p;sc->sc_lock);<br>> =C2=A0>> =C2=A0 =C2=A0 892 if (sc->sc_f=
irst_explore) {<br>> =C2=A0>> =C2=A0 =C2=A0 893 config_pending_dec=
r(sc->sc_dev);<br>> =C2=A0>> =C2=A0 =C2=A0 894 sc->sc_first_=
explore =3D3D false;<br>> =C2=A0>> =C2=A0 =C2=A0 895 }<br>> =C2=
=A0>=3D20<br>> =C2=A0> I don't understand, doesn't it wait=
for subordinate hubs?<br>><br>> =C2=A0Sure, but not long enough...<b=
r>><br>> =C2=A0> ... Maybe the<br>> =C2=A0> USB hub just doe=
sn't report the device ready at first?<br>><br>> =C2=A0Because th=
ere=3DE2=3D80=3D99s no guarantee (afaik) that the root hub will see =3D<br>=
> =C2=A0the built-in hub immediately.</div>
--0000000000001c50be0658580742--
Home |
Main Index |
Thread Index |
Old Index