Re: port-arm/60021: USB-only boot: uhub0 attaches but uhub1 never appears, no hotplug events; SD-boot sees hub+umass fine

"Michael Cheponis via gnats" <[email protected]>
Newsgroups gmane.os.netbsd.bugs
Message-ID <[email protected]>
The following reply was made to PR port-arm/60021; it has been noted by GNATS.

From: Michael Cheponis <[email protected]>
To: [email protected]
Cc: [email protected], [email protected], 
	[email protected], [email protected]
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
 [email protected]:/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]  [email protected]:
 /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 <
 [email protected]> wrote:
 >
 > The following reply was made to PR port-arm/60021; it has been noted by
 GNATS.
 >
 > From: Nick Hudson <[email protected]>
 > To: Taylor R Campbell <[email protected]>
 > Cc: [email protected],
 >  "[email protected]" <[email protected]>,
 >  "[email protected]" <[email protected]>
 > 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 <[email protected]> =3D
 >  wrote:
 >  >=3D20
 >  >> Date: Sat, 21 Feb 2026 10:39:41 +0000
 >  >> From: Nick Hudson <[email protected]>
 >  >>=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 =
 [email protected]:/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] [email protected]:/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&#39;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&#39;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&#39;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: &lt;u=
 nknown&gt;<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}&gt; set $lines =3D 0<br>$lines =C2=A0 =
 =C2=A0 =C2=A0 =C2=A0 =C2=A018 =3D 0<br>db{2}&gt; 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 &#39;usbhist&#39;: at 0xffffc00000d0e058 tot=
 al 50000 next free 366<br>db{2}&gt; 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: &lt;=
 - 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: &lt;- 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: &lt;- =
 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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:=
  &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt=
 ;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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: &lt;- 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}&gt;<br><br>On =
 Tue, Aug 4, 2026 at 11:35=E2=80=AFAM Nick Hudson via gnats &lt;<a href=3D"m=
 ailto:[email protected]">[email protected]</a>&gt; wrote:<br>&gt;=
 <br>&gt; The following reply was made to PR port-arm/60021; it has been not=
 ed by GNATS.<br>&gt;<br>&gt; From: Nick Hudson &lt;<a href=3D"mailto:nick.h=
 [email protected]">[email protected]</a>&gt;<br>&gt; To: Taylor R Campbel=
 l &lt;[email protected]&gt;<br>&gt; Cc: <a href=3D"mailto:[email protected]=
 ">[email protected]</a>,<br>&gt; =C2=A0&quot;<a href=3D"mailto:gnats-bugs@netb=
 sd.org">[email protected]</a>&quot; &lt;[email protected]&gt;,<br>&=
 gt; =C2=A0&quot;<a href=3D"mailto:[email protected]">netbsd-bugs@netbs=
 d.org</a>&quot; &lt;[email protected]&gt;<br>&gt; Subject: Re: port-ar=
 m/60021: USB-only boot: uhub0 attaches but uhub1 never<br>&gt; =C2=A0appear=
 s, no hotplug events; SD-boot sees hub+umass fine<br>&gt; Date: Tue, 4 Aug =
 2026 19:32:12 +0100<br>&gt;<br>&gt; =C2=A0&gt; On 4 Aug 2026, at 14:34, Tay=
 lor R Campbell &lt;[email protected]&gt; =3D<br>&gt; =C2=A0wrote:<br>&gt=
 ; =C2=A0&gt;=3D20<br>&gt; =C2=A0&gt;&gt; Date: Sat, 21 Feb 2026 10:39:41 +0=
 000<br>&gt; =C2=A0&gt;&gt; From: Nick Hudson &lt;<a href=3D"mailto:nick.hud=
 [email protected]">[email protected]</a>&gt;<br>&gt; =C2=A0&gt;&gt;=3D20<br=
 >&gt; =C2=A0&gt;&gt; This is almost certainly that autoconf doesn&#39;t wai=
 t (long enough) for<br>&gt; =C2=A0&gt;&gt; sub-ordintate hubs<br>&gt; =C2=
 =A0&gt;&gt;=3D20<br>&gt; =C2=A0&gt;&gt; <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>&gt; =C2=A0&gt;&gt;=3D20<br>&gt; =C2=A0&gt;&gt; =C2=A0 =
 =C2=A0 880 mutex_enter(&amp;sc-&gt;sc_lock);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =
 =C2=A0 881 sc-&gt;sc_explorepending =3D3D false;<br>&gt; =C2=A0&gt;&gt; =C2=
 =A0 =C2=A0 882 for (int i =3D3D 0; i &lt; sc-&gt;sc_statuslen; i++) {<br>&g=
 t; =C2=A0&gt;&gt; =C2=A0 =C2=A0 883 if (sc-&gt;sc_statuspend[i] !=3D3D 0) {=
 <br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 884 memcpy(sc-&gt;sc_status, sc-&gt;s=
 c_statuspend,<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 885 =C2=A0 =C2=A0sc-&gt;=
 sc_statuslen);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 886 memset(sc-&gt;sc_st=
 atuspend, 0, sc-&gt;sc_statuslen);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 887=
  usb_needs_explore(sc-&gt;sc_hub);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 888=
  break;<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 889 }<br>&gt; =C2=A0&gt;&gt; =
 =C2=A0 =C2=A0 890 }<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 891 mutex_exit(&am=
 p;sc-&gt;sc_lock);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 892 if (sc-&gt;sc_f=
 irst_explore) {<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 893 config_pending_dec=
 r(sc-&gt;sc_dev);<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 894 sc-&gt;sc_first_=
 explore =3D3D false;<br>&gt; =C2=A0&gt;&gt; =C2=A0 =C2=A0 895 }<br>&gt; =C2=
 =A0&gt;=3D20<br>&gt; =C2=A0&gt; I don&#39;t understand, doesn&#39;t it wait=
  for subordinate hubs?<br>&gt;<br>&gt; =C2=A0Sure, but not long enough...<b=
 r>&gt;<br>&gt; =C2=A0&gt; ... Maybe the<br>&gt; =C2=A0&gt; USB hub just doe=
 sn&#39;t report the device ready at first?<br>&gt;<br>&gt; =C2=A0Because th=
 ere=3DE2=3D80=3D99s no guarantee (afaik) that the root hub will see =3D<br>=
 &gt; =C2=A0the built-in hub immediately.</div>
 
 --0000000000001c50be0658580742--
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.