NetBSD Problem Report #50491
From www@NetBSD.org Tue Dec 1 06:45:48 2015
Return-Path: <www@NetBSD.org>
Received: from mail.netbsd.org (mail.netbsd.org [149.20.53.66])
(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
(Client CN "mail.netbsd.org", Issuer "Postmaster NetBSD.org" (verified OK))
by mollari.NetBSD.org (Postfix) with ESMTPS id 2A35EA65CB
for <gnats-bugs@gnats.NetBSD.org>; Tue, 1 Dec 2015 06:45:48 +0000 (UTC)
Message-Id: <20151201064545.C462BA65CE@mollari.NetBSD.org>
Date: Tue, 1 Dec 2015 06:45:45 +0000 (UTC)
From: mfpnb@plass-family.net
Reply-To: mfpnb@plass-family.net
To: gnats-bugs@NetBSD.org
Subject: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
X-Send-Pr-Version: www-1.0
>Number: 50491
>Category: kern
>Synopsis: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: skrll
>State: closed
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Tue Dec 01 06:50:00 +0000 2015
>Closed-Date: Wed Nov 02 08:23:37 +0000 2016
>Last-Modified: Wed Nov 02 08:23:37 +0000 2016
>Originator: Michael Plass
>Release: NetBSD-7.0
>Organization:
>Environment:
NetBSD mipi 7.0 NetBSD 7.0 (RPI2) #0: Thu Oct 29 03:02:03 PDT 2015 michael@home.plass-family.net:/home/michael/NetBSD-7.0/build/usr/src/sys/arch/evbarm/compile/obj/RPI2 evbarm
>Description:
When using the built-in usmsc0 network interface on a raspberry pi 2, a process will occasionally get stuck waiting on usbxfer. When in this state, the process does not respond to signals. Processes that do not use the network can continue; for instance it is usually possible to login on the serial console.
Sometimes, but not always, there are also kernel messages logged - see the bottom of the two dmesg outputs below for a couple of examples.
This example happened while transferring data with ssh:
mipi# Stopped in pid 0.2 (system) at netbsd:cpu_Debugger+0x4: bx r14
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
936 1 3 1 80 b9ee16e0 dd pipe_rd
3388 1 3 3 0 b9ee00e0 ssh usbxfer
2872 1 3 2 80 b9ee19a0 sh wait
2635 1 3 2 80 bac12e60 top ttyout
1598 1 3 3 80 bacc1c00 sh wait
114 1 3 1 80 bac13120 sshd select
1925 1 3 1 80 bac133e0 sshd select
2634 1 3 1 80 bac12360 sh wait
2449 1 3 2 0 bac12ba0 sshd tstile
2127 1 3 1 80 bac12620 sshd select
2303 1 3 1 80 bacfab60 sh ttyraw
2436 1 3 1 80 bacfa320 login wait
2423 1 3 1 80 b9ee0ea0 cron nanoslp
2133 1 3 1 80 b9ee0660 inetd kqueue
2074 1 3 1 80 ba5ae0c0 qmgr kqueue
2009 1 3 3 80 ba5ae640 pickup kqueue
2036 1 3 3 80 b9ee0920 master kqueue
1709 1 3 1 80 ba5ae900 sshd select
1203 1 3 2 80 ba5aebc0 ntpd pause
1411 1 3 1 80 ba5af6c0 devpubd devmon
925 1 3 1 80 ba5afc40 syslogd kqueue
db{0}> bt/tl 0t3388
trace: pid 3388 lid 1 at 0xba7f39cc
0xba7f39cc: netbsd:mi_switch+0x10
0xba7f39fc: netbsd:sleepq_block+0xb4
0xba7f3a2c: netbsd:cv_wait+0x104
0xba7f3a5c: netbsd:usbd_transfer+0x23c
0xba7f3aac: netbsd:usbd_do_request_flags_pipe+0xd8
0xba7f3ad4: netbsd:usbd_do_request+0x38
0xba7f3b04: netbsd:smsc_read_reg+0x60
0xba7f3b2c: netbsd:smsc_wait_for_bits+0x4c
0xba7f3b54: netbsd:smsc_chip_init+0x30
0xba7f3b74: netbsd:smsc_stop+0x274
0xba7f3bac: netbsd:smsc_encap+0xd0
0xba7f3bcc: netbsd:smsc_start+0x6c
0xba7f3bf4: netbsd:ifq_enqueue+0xdc
0xba7f3c3c: netbsd:ether_output+0x2d4
0xba7f3cdc: netbsd:ip_output+0xb60
0xba7f3dbc: netbsd:tcp_output+0x1360
0xba7f3de4: netbsd:tcp_rcvd_wrapper+0x94
0xba7f3e6c: netbsd:soreceive+0x5ac
0xba7f3e84: netbsd:soo_read+0x30
0xba7f3edc: netbsd:dofileread+0x94
0xba7f3f0c: netbsd:sys_read+0x70
0xba7f3f7c: netbsd:syscall+0x88
0xba7f3fac: netbsd:swi_handler+0x98
db{0}> dmesg
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015
The NetBSD Foundation, Inc. All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
NetBSD 7.0 (RPI2) #0: Thu Oct 29 03:02:03 PDT 2015
michael@home.plass-family.net:/home/michael/NetBSD-7.0/build/usr/src/sys
/arch/evbarm/compile/obj/RPI2
total memory = 944 MB
avail memory = 928 MB
sysctl_createv: sysctl_create(machine_arch) returned 17
kern.module.path=/stand/evbarm/7.0/modules
timecounter: Timecounters tick every 10.000 msec
mainbus0 (root)
cpu0 at mainbus0 core 0: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu0: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu0: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu0: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu0: pfr: [0]=0x1131 [1]=0x11011
cpu0: 32KB/32B 2-way L1 VIPT Instruction cache
cpu0: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu0: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp0 at cpu0: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp0: mvfr: [0]=0x10110222 [1]=0x11111111
cpu1 at mainbus0 core 1
cpu2 at mainbus0 core 2
cpu3 at mainbus0 core 3
obio0 at mainbus0
bcmicu0 at obio0: Multiprocessor
armgtmr0 at obio0: ARMv7 Generic 64-bit Timer (19200 kHz)
armgtmr0: interrupting on irq 3
timecounter: Timecounter "armgtmr0" frequency 19200000 Hz quality 500
bcmmbox0 at obio0: VC mailbox
vcmbox0 at bcmmbox0
vchiq0 at obio0 intr 194: BCM2835 VCHIQ
bcmpm0 at obio0: Power management, Reset and Watchdog controller
bcmdmac0 at obio0: DMA0 DMA2 DMA4 DMA5 DMA8 DMA9 DMA10
bcmrng0 at obio0: RNG
plcom0 at obio0 intr 185
plcom0: txfifo disabled
plcom0: console
genfb0 at obio0
genfb0: framebuffer at 0x3d876000, size 1280x720, depth 32, stride 5120
wsdisplay0 at genfb0 kbdmux 1
wsmux1: connecting to wsdisplay0
wsdisplay0: screen 0-3 added (default, vt100 emulation)
sdhc0 at obio0 intr 190: SDHC controller
sdhc0: interrupting on intr 190
dwctwo0 at obio0 intr 137: USB controller
bcmspi0 at obio0 intr 182: SPI
spi0 at bcmspi0: SPI bus
bsciic0 at obio0 intr 181: BSC0
iic0 at bsciic0: I2C bus
bsciic1 at obio0 intr 181: BSC1
iic1 at bsciic1: I2C bus
bcmgpio0 at obio0: GPIO [0...31]
gpio0 at bcmgpio0: 32 pins
bcmgpio1 at obio0: GPIO [32...53]
gpio1 at bcmgpio1: 22 pins
usb0 at dwctwo0: USB revision 2.0
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
cpu3: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu3: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu3: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu3: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu3: pfr: [0]=0x1131 [1]=0x11011
cpu3: 32KB/32B 2-way L1 VIPT Instruction cache
cpu3: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu3: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp3 at cpu3: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp3: mvfr: [0]=0x10110222 [1]=0x11111111
cpu1: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu1: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu1: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu1: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu1: pfr: [0]=0x1131 [1]=0x11011
cpu1: 32KB/32B 2-way L1 VIPT Instruction cache
cpu1: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu1: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp1 at cpu1: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp1: mvfr: [0]=0x10110222 [1]=0x11111111
cpu2: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu2: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu2: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu2: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu2: pfr: [0]=0x1131 [1]=0x11011
cpu2: 32KB/32B 2-way L1 VIPT Instruction cache
cpu2: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu2: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp2 at cpu2: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp2: mvfr: [0]=0x10110222 [1]=0x11111111
sdhc0: SD Host Specification 3.0, rev.153
sdhc0: using DMA transfer
sdmmc0 at sdhc0 slot 0
uhub0 at usb0: vendor 0x0000 DWC2 root hub, class 9/0, rev 2.00/1.00, addr 1
uhub0: 1 port with 1 removable, self powered
ld0 at sdmmc0: <0x03:0x5344:SU08G:0x80:0x611ed719:0x0e5>
ld0: 7580 MB, 3850 cyl, 64 head, 63 sec, 512 bytes/sect x 15523840 sectors
ld0: 4-bit width, bus clock 50.000 MHz
uhub1 at uhub0 port 1: vendor 0x0424 product 0x9514, class 9/0, rev 2.00/2.00, a
ddr 2
uhub1: multiple transaction translators
uhub1: 5 ports with 4 removable, self powered
usmsc0 at uhub1 port 1
usmsc0: vendor 0x0424 product 0xec00, rev 2.00/2.00, addr 3
usmsc0: Ethernet address b8:27:eb:19:a8:ec
ukphy0 at usmsc0 phy 1: OUI 0x00800f, model 0x000c, rev. 3
ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
umidi_search_quirk: v=1204, p=26672, i=0
umass0 at uhub1 port 3 configuration 1 interface 0
umass0: vendor 0x04b4 Cypress AT2LP RC42, rev 2.00/4.20, addr 4
umass0: using SCSI over Bulk-Only
scsibus0 at umass0: 2 targets, 1 lun per target
sd0 at scsibus0 target 0 lun 0: <SAMSUNG, SP1604N, 0000> disk fixed
umass0: dCSWDataResidue=20 req=40 act=40
sd0: 149 GB, 16383 cyl, 16 head, 63 sec, 512 bytes/sect x 312581808 sectors
boot device: ld0
root on ld0a dumps on ld0b
root file system type: ffs
vchiq: local ver 6 (min 3), remote ver 6.
vcaudio0 at vchiq0: auds
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
audio0 at vcaudio0: half duplex, playback, capture, independent
umass0: dCSWDataResidue=20 req=40 act=40
wsdisplay0: screen 4 added (default, vt100 emulation)
usb_insert_transfer: xfer=0xbacb9440 not busy 0x0000009e
Another example, while stopping mdnsd:
Stopped in pid 0.2 (system) at netbsd:cpu_Debugger+0x4: bx r14
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
2508 1 3 1 80 ba55f140 tset nanoslp
2613 1 3 1 80 baba68e0 sh pipe_rd
2873 1 3 0 80 baba6360 sleep nanoslp
264 1 3 0 80 ba55f400 sh wait
1966 1 3 0 1000000 ba55f6c0 ntpd tstile
1626 1 3 1 80 b9c963a0 pickup kqueue
70 1 3 0 80 baba6620 sh wait
73 1 3 1 80 baba6e60 su wait
2442 1 3 1 80 b9c96ea0 sh wait
2422 1 3 1 0 b88a7700 sshd tstile
2181 1 3 1 80 bacfae20 login wait
2255 1 3 1 80 b88a7180 cron nanoslp
2308 1 3 1 80 b88a7c80 sshd select
2339 1 3 1 80 b9c960e0 inetd kqueue
2015 1 3 2 0 b9c96920 mdnsd usbxfer
2061 1 3 1 80 b9c96660 qmgr kqueue
1908 1 3 1 80 b88a79c0 master kqueue
1291 1 3 1 80 b9c96be0 sshd select
1464 1 3 1 80 baba60a0 devpubd devmon
859 1 3 1 80 ba55ee80 syslogd kqueue
541 1 3 3 80 ba55f980 dhcpcd select
1 1 3 1 80 bacc1100 init wait
0 64 3 1 200 bacc0e40 physiod physiod
0 63 3 1 200 baba7c20 aiodoned aiodoned
0 62 3 1 200 bacfa5e0 ioflush syncer
0 61 3 1 200 bacfab60 pgdaemon pgdaemon
0 60 3 1 280 bacc0080 VCHIQka-0 lnxcmplt
0 59 3 1 280 bacc0340 vcaudio data
0 58 3 1 280 bacc0600 VCHIQs-0 semacv
0 57 3 1 280 bacc08c0 VCHIQr-0 semacv
0 56 3 1 280 bacc0b80 VCHIQ-0 semacv
0 53 3 1 200 bacfa8a0 usb0 usbevt
0 52 3 1 200 bacfa320 unpgc unpgc
0 50 3 1 200 bacc1940 vmem_rehash vmem_rehash
0 49 3 0 200 bacc13c0 sdmmc0 mmctaskq
0 48 3 1 200 bacc1680 vcmbox0 vcmbox0
0 39 3 1 200 bacfb0e0 usbtask-dr usbxfer
0 38 3 1 200 bacfb3a0 usbtask-hc usbtsk
0 37 3 1 200 bacfb660 dwc2 dwc2
0 36 3 3 200 bacfb920 iic1 iicintr
0 35 3 0 200 bacfbbe0 iic0 iicintr
0 34 3 1 200 bada4040 sysmon smtaskq
0 33 3 3 200 bada4300 xcall/3 xcall
0 32 1 3 200 bada45c0 softser/3
0 31 1 3 200 bada4880 softclk/3
0 30 1 3 200 bada4b40 softbio/3
0 29 1 3 200 bada4e00 softnet/3
0 > 28 7 3 201 bada50c0 idle/3
0 27 3 2 200 bada5380 xcall/2 xcall
0 26 1 2 200 bada5640 softser/2
0 25 1 2 200 bada5900 softclk/2
0 24 1 2 200 bada5bc0 softbio/2
0 23 1 2 200 badd4020 softnet/2
0 > 22 7 2 201 badd42e0 idle/2
0 21 3 1 200 badd45a0 xcall/1 xcall
0 20 1 1 200 badd4860 softser/1
0 19 3 1 200 badd4b20 softclk/1 tstile
0 18 1 1 200 badd4de0 softbio/1
0 17 1 1 200 badd50a0 softnet/1
0 > 16 7 1 201 badd5360 idle/1
0 15 3 1 200 badd5620 pmfsuspend pmfsuspend
0 14 3 1 200 badd58e0 pmfevent pmfevent
0 13 3 1 200 badd5ba0 sopendfree sopendfr
0 12 3 1 200 baf04000 nfssilly nfssilly
0 11 3 1 200 baf042c0 cachegc cachegc
0 10 3 2 200 baf04580 vrele vrele
0 9 3 0 200 baf04840 vdrain vdrain
0 8 3 1 200 baf04b00 modunload mod_unld
0 7 3 0 200 baf04dc0 xcall/0 xcall
0 6 1 0 200 baf05080 softser/0
0 5 3 0 200 baf05340 softclk/0 tstile
0 4 1 0 200 baf05600 softbio/0
0 3 3 0 200 baf058c0 softnet/0 tstile
0 > 2 7 0 201 baf05b80 idle/0
0 1 3 1 200 805718c0 swapper uvm
db{0}> bt/t 0t2015
trace: pid 2015 lid 1 at 0xb98a7b54
0xb98a7b54: netbsd:mi_switch+0x10
0xb98a7b84: netbsd:sleepq_block+0xb4
0xb98a7bb4: netbsd:cv_wait+0x104
0xb98a7be4: netbsd:usbd_transfer+0x23c
0xb98a7c34: netbsd:usbd_do_request_flags_pipe+0xd8
0xb98a7c5c: netbsd:usbd_do_request+0x38
0xb98a7c8c: netbsd:smsc_write_reg+0x60
0xb98a7cb4: netbsd:smsc_setmulti+0x110
0xb98a7ce4: netbsd:smsc_ioctl+0x124
0xb98a7d8c: netbsd:if_mcast_op+0x50
0xb98a7db4: netbsd:in_delmulti+0x78
0xb98a7dd4: netbsd:ip_freemoptions+0x34
0xb98a7df4: netbsd:in_pcbdetach+0xac
0xb98a7e14: netbsd:udp_detach_wrapper+0x40
0xb98a7e3c: netbsd:soclose+0x7c
0xb98a7e54: netbsd:soo_close+0x20
0xb98a7e94: netbsd:closef+0x6c
0xb98a7ef4: netbsd:fd_close+0x180
0xb98a7f0c: netbsd:sys_close+0x2c
0xb98a7f7c: netbsd:syscall+0x88
0xb98a7fac: netbsd:swi_handler+0x98
db{0}> dmesg
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015
The NetBSD Foundation, Inc. All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
NetBSD 7.0 (RPI2) #0: Thu Oct 29 03:02:03 PDT 2015
michael@home.plass-family.net:/home/michael/NetBSD-7.0/build/usr/src/sys
/arch/evbarm/compile/obj/RPI2
total memory = 944 MB
avail memory = 928 MB
sysctl_createv: sysctl_create(machine_arch) returned 17
kern.module.path=/stand/evbarm/7.0/modules
timecounter: Timecounters tick every 10.000 msec
mainbus0 (root)
cpu0 at mainbus0 core 0: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu0: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu0: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu0: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu0: pfr: [0]=0x1131 [1]=0x11011
cpu0: 32KB/32B 2-way L1 VIPT Instruction cache
cpu0: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu0: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp0 at cpu0: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp0: mvfr: [0]=0x10110222 [1]=0x11111111
cpu1 at mainbus0 core 1
cpu2 at mainbus0 core 2
cpu3 at mainbus0 core 3
obio0 at mainbus0
bcmicu0 at obio0: Multiprocessor
armgtmr0 at obio0: ARMv7 Generic 64-bit Timer (19200 kHz)
armgtmr0: interrupting on irq 3
timecounter: Timecounter "armgtmr0" frequency 19200000 Hz quality 500
bcmmbox0 at obio0: VC mailbox
vcmbox0 at bcmmbox0
vchiq0 at obio0 intr 194: BCM2835 VCHIQ
bcmpm0 at obio0: Power management, Reset and Watchdog controller
bcmdmac0 at obio0: DMA0 DMA2 DMA4 DMA5 DMA8 DMA9 DMA10
bcmrng0 at obio0: RNG
plcom0 at obio0 intr 185
plcom0: txfifo disabled
plcom0: console
genfb0 at obio0
genfb0: framebuffer at 0x3d876000, size 1280x720, depth 32, stride 5120
wsdisplay0 at genfb0 kbdmux 1
wsmux1: connecting to wsdisplay0
wsdisplay0: screen 0-3 added (default, vt100 emulation)
sdhc0 at obio0 intr 190: SDHC controller
sdhc0: interrupting on intr 190
dwctwo0 at obio0 intr 137: USB controller
bcmspi0 at obio0 intr 182: SPI
spi0 at bcmspi0: SPI bus
bsciic0 at obio0 intr 181: BSC0
iic0 at bsciic0: I2C bus
bsciic1 at obio0 intr 181: BSC1
iic1 at bsciic1: I2C bus
bcmgpio0 at obio0: GPIO [0...31]
gpio0 at bcmgpio0: 32 pins
bcmgpio1 at obio0: GPIO [32...53]
gpio1 at bcmgpio1: 22 pins
usb0 at dwctwo0: USB revision 2.0
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
cpu1: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu1: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu1: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu1: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu1: pfr: [0]=0x1131 [1]=0x11011
cpu1: 32KB/32B 2-way L1 VIPT Instruction cache
cpu1: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu1: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp1 at cpu1: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp1: mvfr: [0]=0x10110222 [1]=0x11111111
cpu3: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu3: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu3: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu3: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu3: pfr: [0]=0x1131 [1]=0x11011
cpu3: 32KB/32B 2-way L1 VIPT Instruction cache
cpu3: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu3: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp3 at cpu3: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp3: mvfr: [0]=0x10110222 [1]=0x11111111
cpu2: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu2: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu2: isar: [0]=0x2101110 [1]=0x13112111 [2]=0x21232041 [3]=0x11112131, [4]=0x10
011142, [5]=0
cpu2: mmfr: [0]=0x10101105 [1]=0x40000000 [2]=0x1240000 [3]=0x2102211
cpu2: pfr: [0]=0x1131 [1]=0x11011
cpu2: 32KB/32B 2-way L1 VIPT Instruction cache
cpu2: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu2: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp2 at cpu2: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
vfp2: mvfr: [0]=0x10110222 [1]=0x11111111
sdhc0: SD Host Specification 3.0, rev.153
sdhc0: using DMA transfer
sdmmc0 at sdhc0 slot 0
uhub0 at usb0: vendor 0x0000 DWC2 root hub, class 9/0, rev 2.00/1.00, addr 1
uhub0: 1 port with 1 removable, self powered
ld0 at sdmmc0: <0x03:0x5344:SU08G:0x80:0x611ed719:0x0e5>
ld0: 7580 MB, 3850 cyl, 64 head, 63 sec, 512 bytes/sect x 15523840 sectors
ld0: 4-bit width, bus clock 50.000 MHz
uhub1 at uhub0 port 1: vendor 0x0424 product 0x9514, class 9/0, rev 2.00/2.00, a
ddr 2
uhub1: multiple transaction translators
uhub1: 5 ports with 4 removable, self powered
usmsc0 at uhub1 port 1
usmsc0: vendor 0x0424 product 0xec00, rev 2.00/2.00, addr 3
usmsc0: Ethernet address b8:27:eb:19:a8:ec
ukphy0 at usmsc0 phy 1: OUI 0x00800f, model 0x000c, rev. 3
ukphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
boot device: ld0
root on ld0a dumps on ld0b
root file system type: ffs
vchiq: local ver 6 (min 3), remote ver 6.
vcaudio0 at vchiq0: auds
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
audio0 at vcaudio0: half duplex, playback, capture, independent
wsdisplay0: screen 4 added (default, vt100 emulation)
usbd_do_request: not in process context
usmsc0: warning: Failed to write register 0x10c
usbd_do_request: not in process context
usmsc0: warning: Failed to write register 0x110
usbd_do_request: not in process context
usmsc0: warning: Failed to write register 0x100
db{0}> sync
syncing disks... 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 25 giving up
dump to dev 92,1 not possible
rebooting...
>How-To-Repeat:
It can happen anytime the usmsc0 network interface is in use, but one of the more likely ways to provoke it is to close a multicast socket.
For instance,
# service mdnsd restart
It won't happen all the time, so many repetitions may be required.
The problem becomes less likely to happen when all but one CPU is taken offline; I have had an uptime of several days of normal use this way, but eventually the problem did occur.
To rule out any obvious hardware problem, I ran continuous network transfers while running raspbian for several days, without any problems.
>Fix:
>Release-Note:
>Audit-Trail:
Responsible-Changed-From-To: kern-bug-people->skrll
Responsible-Changed-By: skrll@NetBSD.org
Responsible-Changed-When: Tue, 01 Dec 2015 08:44:44 +0000
Responsible-Changed-Why:
I should take this one
From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org,
gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Tue, 1 Dec 2015 14:33:58 +0000
This is a multi-part message in MIME format.
--------------060900050601040906010405
Content-Type: text/plain; charset=windows-1252; format=flowed
Content-Transfer-Encoding: 7bit
On 12/01/15 06:50, mfpnb@plass-family.net wrote:
>> Number: 50491
>> Category: kern
>> Synopsis: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
> usbd_do_request: not in process context
> usmsc0: warning: Failed to write register 0x10c
> usbd_do_request: not in process context
> usmsc0: warning: Failed to write register 0x110
> usbd_do_request: not in process context
> usmsc0: warning: Failed to write register 0x100
Please run with this patch to help determine why this is happening.
It will drop to debugger where you can get a backtrace.
Thanks,
Nick
--------------060900050601040906010405
Content-Type: text/x-patch;
name="pr50491.diff"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
filename="pr50491.diff"
Index: sys/dev/usb/usbdi.c
===================================================================
RCS file: /cvsroot/src/sys/dev/usb/usbdi.c,v
retrieving revision 1.161.2.1
diff -u -p -r1.161.2.1 usbdi.c
--- sys/dev/usb/usbdi.c 11 Feb 2015 09:32:19 -0000 1.161.2.1
+++ sys/dev/usb/usbdi.c 1 Dec 2015 14:33:00 -0000
@@ -992,6 +992,8 @@ usbd_do_request_flags_pipe(usbd_device_h
usbd_xfer_handle xfer;
usbd_status err;
+ ASSERT_SLEEPABLE();
+
#ifdef DIAGNOSTIC
if (cpu_intr_p() || cpu_softintr_p()) {
printf("usbd_do_request: not in process context\n");
--------------060900050601040906010405--
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc: Michael Plass <mfpnb@plass-family.net>
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Tue, 1 Dec 2015 20:55:32 -0800
On Dec 1, 2015, at 12:50 PM, Nick Hudson wrote:
> The following reply was made to PR kern/50491; it has been noted by =
GNATS.
>=20
> From: Nick Hudson <skrll@netbsd.org>
> To: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org,
> gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
> Cc:=20
> Subject: Re: kern/50491: unkillable wait in usbd_transfer while using =
usmsc0
> on raspberry pi 2
> Date: Tue, 1 Dec 2015 14:33:58 +0000
>=20
> This is a multi-part message in MIME format.
> --------------060900050601040906010405
> Content-Type: text/plain; charset=3Dwindows-1252; format=3Dflowed
> Content-Transfer-Encoding: 7bit
>=20
> On 12/01/15 06:50, mfpnb@plass-family.net wrote:
>>> Number: 50491
>>> Category: kern
>>> Synopsis: unkillable wait in usbd_transfer while using usmsc0 =
on raspberry pi 2
>=20
>=20
>> usbd_do_request: not in process context
>> usmsc0: warning: Failed to write register 0x10c
>> usbd_do_request: not in process context
>> usmsc0: warning: Failed to write register 0x110
>> usbd_do_request: not in process context
>> usmsc0: warning: Failed to write register 0x100
>=20
>=20
> Please run with this patch to help determine why this is happening.
>=20
> It will drop to debugger where you can get a backtrace.
>=20
> Thanks,
> Nick
>=20
> --------------060900050601040906010405
> Content-Type: text/x-patch;
> name=3D"pr50491.diff"
> Content-Transfer-Encoding: 7bit
> Content-Disposition: attachment;
> filename=3D"pr50491.diff"
>=20
> Index: sys/dev/usb/usbdi.c
> =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
> RCS file: /cvsroot/src/sys/dev/usb/usbdi.c,v
> retrieving revision 1.161.2.1
> diff -u -p -r1.161.2.1 usbdi.c
> --- sys/dev/usb/usbdi.c 11 Feb 2015 09:32:19 -0000 =
1.161.2.1
> +++ sys/dev/usb/usbdi.c 1 Dec 2015 14:33:00 -0000
> @@ -992,6 +992,8 @@ usbd_do_request_flags_pipe(usbd_device_h
> usbd_xfer_handle xfer;
> usbd_status err;
>=20
> + ASSERT_SLEEPABLE();
> +
> #ifdef DIAGNOSTIC
> if (cpu_intr_p() || cpu_softintr_p()) {
> printf("usbd_do_request: not in process context\n");
>=20
> --------------060900050601040906010405--
>=20
>=20
>=20
I'm running with the patch, and I still get the hangs, but so far this =
condition has not been hit. I'll keep trying.
- Michael=
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc: Michael Plass <mfpnb@plass-family.net>
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Wed, 2 Dec 2015 21:26:11 -0800
Nick,
I saw one of the 'usbd_do_request: not in process context' messages go =
by
(actually while still coming up to multiuser mode), but apparently DEBUG =
was
not defined, so the ASSERT_SLEEPABLE() was a NOP. I've rebuilt with a =
call to
assert_sleepable() instead, and I'll run with that.
That particular message was not accompanied by a hang.
Meanwhile, I've tried running with usbdebug and dwc2debug set. Luckily =
the hang
still happens, I think even more readily than without the debug output. =
(I also
stopped syslogd to squelch some noise messages from the sd card.)
Below are the last ~1k lines.
Thanks,
- Michael
db{0}> write/l usbdebug 11
netbsd:usbdebug 0 =3D 11
db{0}> write/l dwc2debug 1
netbsd:dwc2debug 0 =3D 1
db{0}> cont
...
usb_add_task: task=3D0xbac3d344
usb_task_thread: woke up task=3D0xbac3d344
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_schedsoftintr: polling=3D0
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usb_transfer_complete: pipe=3D0xbafa0630 xfer=3D0xbacb9b00 status=3D0 =
actlen=3D142
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9b00
usbd_transfer: xfer=3D0xbacb9b00, flags=3D0x5, pipe=3D0xbafa0630, =
running=3D1
usbd_dump_queue: pipe=3D0xbafa0630
dwc2_device_bulk_transfer: xfer=3D0xbacb9b00
usb_insert_transfer: pipe=3D0xbafa0630 running=3D1 timeout=3D0
usbd_start_next: pipe=3D0xbafa0630, xfer=3D0xbacb9b00
dwc2_device_bulk_start: xfer=3D0xbacb9b00
dwc2_device_start: xfer=3D0xbacb9b00 pipe=3D0xbafa0630
dwctwo0: urb=3D0xbad7aa88, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0630 xfer=3D0xbacb9b00 status=3D0 =
actlen=3D128
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9b00
usbd_transfer: xfer=3D0xbacb9b00, flags=3D0x5, pipe=3D0xbafa0630, =
running=3D1
usbd_dump_queue: pipe=3D0xbafa0630
dwc2_device_bulk_transfer: xfer=3D0xbacb9b00
usb_insert_transfer: pipe=3D0xbafa0630 running=3D1 timeout=3D0
usbd_start_next: pipe=3D0xbafa0630, xfer=3D0xbacb9b00
dwc2_device_bulk_start: xfer=3D0xbacb9b00
dwc2_device_start: xfer=3D0xbacb9b00 pipe=3D0xbafa0630
dwctwo0: urb=3D0xbad7aa88, xfer=3D0x0
usbd_transfer: xfer=3D0xbacb9a40, flags=3D0x9, pipe=3D0xbafa05c0, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa05c0
dwc2_device_bulk_transfer: xfer=3D0xbacb9a40
usb_insert_transfer: pipe=3D0xbafa05c0 running=3D0 timeout=3D10000
dwc2_device_bulk_start: xfer=3D0xbacb9a40
dwc2_device_start: xfer=3D0xbacb9a40 pipe=3D0xbafa05c0
dwctwo0: urb=3D0xbad7a908, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa05c0 xfer=3D0xbacb9a40 status=3D0 =
actlen=3D126
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9a40
usbd_start_next: pipe=3D0xbafa05c0, xfer=3D0x0
usb_transfer_complete: pipe=3D0xbafa0630 xfer=3D0xbacb9b00 status=3D0 =
actlen=3D76
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9b00
usbd_transfer: xfer=3D0xbacb9b00, flags=3D0x5, pipe=3D0xbafa0630, =
running=3D1
usbd_dump_queue: pipe=3D0xbafa0630
dwc2_device_bulk_transfer: xfer=3D0xbacb9b00
usb_insert_transfer: pipe=3D0xbafa0630 running=3D1 timeout=3D0
usbd_start_next: pipe=3D0xbafa0630, xfer=3D0xbacb9b00
dwc2_device_bulk_start: xfer=3D0xbacb9b00
dwc2_device_start: xfer=3D0xbacb9b00 pipe=3D0xbafa0630
dwctwo0: urb=3D0xbad7aa88, xfer=3D0x0
usb_add_task: task=3D0xbac3d344
usb_task_thread: woke up task=3D0xbac3d344
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_alloc_xfer() =3D 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9ec0, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9ec0 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb86e2648, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9ec0 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9ec0
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9ec0
usbd_transfer: xfer=3D0xbacb9a40, flags=3D0x9, pipe=3D0xbafa05c0, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa05c0
dwc2_device_bulk_transfer: xfer=3D0xbacb9a40
usb_insert_transfer: pipe=3D0xbafa05c0 running=3D0 timeout=3D10000
dwc2_device_bulk_start: xfer=3D0xbacb9a40
dwc2_device_start: xfer=3D0xbacb9a40 pipe=3D0xbafa05c0
dwctwo0: urb=3D0xbad7a908, xfer=3D0x0
usbd_alloc_xfer() =3D 0xbacb9980
usbd_transfer: xfer=3D0xbacb9980, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9980 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb5f6bb88, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa05c0 xfer=3D0xbacb9a40 status=3D0 =
actlen=3D142
usb_schedsoftintr: polling=3D0
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9a40
usbd_start_next: pipe=3D0xbafa05c0, xfer=3D0x0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9980 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9980
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9980
usbd_alloc_xfer() =3D 0xbacb9980
usbd_transfer: xfer=3D0xbacb9980, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9980 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb5f6bb88, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9980 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9980
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9980
usbd_alloc_xfer() =3D 0xbacb9980
usbd_transfer: xfer=3D0xbacb9980, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9980 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb5f6bb88, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_schedsoftintr: polling=3D0
usb_transfer_complete: pipe=3D0xbafa0630 xfer=3D0xbacb9b00 status=3D0 =
actlen=3D76
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_bulk_done: xfer=3D0xbacb9b00
usbd_transfer: xfer=3D0xbacb9b00, flags=3D0x5, pipe=3D0xbafa0630, =
running=3D1
usbd_dump_queue: pipe=3D0xbafa0630
dwc2_device_bulk_transfer: xfer=3D0xbacb9b00
usb_insert_transfer: pipe=3D0xbafa0630 running=3D1 timeout=3D0
usbd_start_next: pipe=3D0xbafa0630, xfer=3D0xbacb9b00
dwc2_device_bulk_start: xfer=3D0xbacb9b00
dwc2_device_start: xfer=3D0xbacb9b00 pipe=3D0xbafa0630
dwctwo0: urb=3D0xbad7aa88, xfer=3D0x0
usb_transfer_complete: pipe=3D0xbafa0780 xfer=3D0xbacb9980 status=3D0 =
actlen=3D4
usb_freemem: frag=3D0xc90acd80
usb_transfer_complete: repeat=3D0 new head=3D0x0
dwc2_device_ctrl_done: xfer=3D0xbacb9980
usbd_start_next: pipe=3D0xbafa0780, xfer=3D0x0
usbd_free_xfer: 0xbacb9980
usbd_transfer: xfer=3D0xbacb9a40, flags=3D0x9, pipe=3D0xbafa05c0, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa05c0
dwc2_device_bulk_transfer: xfer=3D0xbacb9a40
usb_insert_transfer: pipe=3D0xbafa05c0 running=3D0 timeout=3D10000
dwc2_device_bulk_start: xfer=3D0xbacb9a40
dwc2_device_start: xfer=3D0xbacb9a40 pipe=3D0xbafa05c0
dwctwo0: urb=3D0xbad7a908, xfer=3D0x0
usbd_alloc_xfer() =3D 0xbacb9980
usbd_transfer: xfer=3D0xbacb9980, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D0
usbd_dump_queue: pipe=3D0xbafa0780
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D0 timeout=3D5000
dwc2_device_ctrl_start:=20
dwc2_device_start: xfer=3D0xbacb9980 pipe=3D0xbafa0780
dwctwo0: urb=3D0xb5f6bb88, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_schedsoftintr: polling=3D0
usb_schedsoftintr: polling=3D0
mipi#=20
mipi#=20
mipi#=20
mipi# Stopped in pid 0.2 (system) at netbsd:cpu_Debugger+0x4: bx =
r14
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
230 1 3 0 0 bacfab60 cleanup tstile
232 1 3 0 80 ba46b140 sleep nanoslp
963 1 3 0 80 baba88e0 sh wait
146 1 3 0 40080 baba8ba0 sh wait
98 1 3 0 80 b9686100 sh wait
105 1 3 3 80 b96863c0 su wait
2020 1 3 1 80 b9687700 pickup select
2107 1 3 3 80 bacfae20 sh wait
2583 1 3 3 0 ba46a0c0 sshd tstile
2623 1 3 0 80 ba16ebe0 sshd select
2173 1 3 1 80 baba8620 sh ttyraw
2526 1 3 1 80 bacc1c00 login wait
2030 1 3 1 80 b7ef2ee0 cron nanoslp
1997 1 3 3 80 b7ef31a0 inetd kqueue
2155 1 3 1 0 b7ef3720 mdnsd usbxfer
2035 1 3 1 80 b9687440 qmgr kqueue
1941 1 3 1 80 b7ef3460 master kqueue
1818 1 3 0 80 ba46b6c0 sshd select
1647 1 2 2 1000000 b96879c0 ntpd
1334 1 3 1 80 baba8360 devpubd devmon
613 1 3 3 80 ba46bc40 dhcpcd select
1 1 3 1 80 bacc1100 init wait
0 64 3 3 200 bacc0e40 physiod physiod
0 63 3 1 200 baba9960 aiodoned =
aiodoned
0 62 3 1 200 baba9c20 ioflush syncer
0 61 3 2 200 bacfa320 pgdaemon =
pgdaemon
0 60 3 2 280 bacc0080 VCHIQka-0 =
lnxcmplt
0 59 3 2 280 bacc0340 vcaudio data
0 58 3 2 280 bacc0600 VCHIQs-0 semacv
0 57 3 0 280 bacc08c0 VCHIQr-0 semacv
0 56 3 2 280 bacc0b80 VCHIQ-0 semacv
0 53 3 2 200 bacfa060 usb0 usbevt
0 51 3 2 200 bacfa5e0 unpgc unpgc
0 50 3 3 200 bacc1940 vmem_rehash =
vmem_rehash
0 49 3 1 200 bacc13c0 sdmmc0 =
mmctaskq
0 48 3 3 200 bacc1680 vcmbox0 vcmbox0
0 39 3 3 200 bacfb0e0 usbtask-dr usbtsk
0 38 3 0 200 bacfb3a0 usbtask-hc usbtsk
0 37 3 0 200 bacfb660 dwc2 dwc2
0 36 3 3 200 bacfb920 iic1 iicintr
0 35 3 1 200 bacfbbe0 iic0 iicintr
0 34 3 0 200 bada4040 sysmon smtaskq
0 33 3 3 200 bada4300 xcall/3 xcall
0 32 1 3 200 bada45c0 softser/3
0 31 3 3 200 bada4880 softclk/3 tstile
0 30 1 3 200 bada4b40 softbio/3
0 29 1 3 200 bada4e00 softnet/3
0 > 28 7 3 201 bada50c0 idle/3
0 27 3 2 200 bada5380 xcall/2 xcall
0 26 1 2 200 bada5640 softser/2
0 25 1 2 200 bada5900 softclk/2
0 24 1 2 200 bada5bc0 softbio/2
0 23 1 2 200 badd4020 softnet/2
0 > 22 7 2 201 badd42e0 idle/2
0 21 3 1 200 badd45a0 xcall/1 xcall
0 20 1 1 200 badd4860 softser/1
0 19 1 1 200 badd4b20 softclk/1
0 18 1 1 200 badd4de0 softbio/1
0 17 1 1 200 badd50a0 softnet/1
0 > 16 7 1 201 badd5360 idle/1
0 15 3 2 200 badd5620 pmfsuspend =
pmfsuspend
0 14 3 1 200 badd58e0 pmfevent =
pmfevent
0 13 3 0 200 badd5ba0 sopendfree =
sopendfr
0 12 3 2 200 baf04000 nfssilly =
nfssilly
0 11 3 3 200 baf042c0 cachegc cachegc
0 10 3 3 200 baf04580 vrele vrele
0 9 3 2 200 baf04840 vdrain vdrain
0 8 3 0 200 baf04b00 modunload =
mod_unld
0 7 3 0 200 baf04dc0 xcall/0 xcall
0 6 1 0 200 baf05080 softser/0
0 5 3 0 200 baf05340 softclk/0 tstile
0 4 1 0 200 baf05600 softbio/0
0 3 3 0 200 baf058c0 softnet/0 tstile
0 > 2 7 0 201 baf05b80 idle/0
0 1 3 3 200 805718c0 swapper uvm
db{0}> bt/t 0t2155
trace: pid 2155 lid 1 at 0xb7d9bb1c
0xb7d9bb1c: netbsd:mi_switch+0x10
0xb7d9bb4c: netbsd:sleepq_block+0xb4
0xb7d9bb7c: netbsd:cv_wait+0x104
0xb7d9bbac: netbsd:usbd_transfer+0x23c
0xb7d9bbfc: netbsd:usbd_do_request_flags_pipe+0xdc
0xb7d9bc24: netbsd:usbd_do_request+0x38
0xb7d9bc54: netbsd:smsc_write_reg+0x60
0xb7d9bc7c: netbsd:smsc_setmulti+0x100
0xb7d9bcac: netbsd:smsc_ioctl+0x124
0xb7d9bd54: netbsd:if_mcast_op+0x50
0xb7d9bda4: netbsd:in6_delmulti+0x154
0xb7d9bdbc: netbsd:in6_leavegroup+0x20
0xb7d9bdd4: netbsd:ip6_freemoptions+0x3c
0xb7d9bdf4: netbsd:in6_pcbdetach+0xc8
0xb7d9be14: netbsd:udp6_detach_wrapper+0x4c
0xb7d9be3c: netbsd:soclose+0x7c
0xb7d9be54: netbsd:soo_close+0x20
0xb7d9be94: netbsd:closef+0x6c
0xb7d9bef4: netbsd:fd_close+0x180
0xb7d9bf0c: netbsd:sys_close+0x2c
0xb7d9bf7c: netbsd:syscall+0x88
0xb7d9bfac: netbsd:swi_handler+0x98
db{0}> call usbd_dump_queue(0xbafa0780)
usbd_dump_queue: pipe=3D0xbafa0780
xfer=3D0xbacb9980
7
db{0}> callouts
No such command: callouts
db{0}> callout
hardclock_ticks now: 44537
ticks wheel arg func
-4591 -1/-256 0 if_slowtimo
-4591 -1/-256 0 nd6_timer
-4690 -1/-256 bad7680c vcons_intr
-4682 -1/-256 0 rt_timer_timer
-4678 -1/-256 0 sched_balance
-4663 -1/-256 bac3d008 smsc_tick
-4506 -1/-256 ba46b140 sleepq_timeout
-2521 -1/-256 baf9c148 sme_events_check
100 -1/-256 baf04840 sleepq_timeout
-4634 -1/-256 805718c0 sleepq_timeout
-4632 -1/-256 bacfb920 sleepq_timeout
-4606 -1/-256 baf04580 sleepq_timeout
-4556 -1/-256 baf042c0 sleepq_timeout
-3863 -1/-256 0 vmem_rehash_all_kick
22 0/48 b9e23ef0 realtimerexpire
48 0/74 bacfbbe0 sleepq_timeout
15 0/74 0 tcp_slowtimo
20 0/79 0 pfslowtimo
20 0/79 0 pffasttimo
72 0/98 baba9c20 sleepq_timeout
21624 1/260 0 arptimer
24560 1/272 b9687440 sleepq_timeout
27860 1/284 b9e23d90 realtimerexpire
31875 1/300 b9e23e40 realtimerexpire
1231 1/351 bacfa060 sleepq_timeout
875 1/435 b7ef2ee0 sleepq_timeout
4575 1/449 b7ef3460 sleepq_timeout
141381 2/514 ba46bc40 sleepq_timeout
315477 2/517 0 nd6_slowtimo
356174 2/518 b9687700 sleepq_timeout
592558 2/521 b9e23ce0 realtimerexpire
715004 2/523 ba7958c0 tcp_timer_keep
8540577 2/642 0 in6_tmpaddrtimer
8605062 2/643 ba807158 nd6_llinfo_timer
db{0}> show all cpus
No such command: cpus
db{0}> help
b delete match search w
break dmesg next set watch
bt dwatch p show whatis
c examine print sifting write
call exit ps step x
callout help quit sync
continue kill reboot trace
d machine s until
db{0}> x/i softint_trigger,10
netbsd:softint_trigger: mrc p15, 0, r3, c13, c0, 4
netbsd:softint_trigger+0x4: ldr r2, [r3, #0x184]
netbsd:softint_trigger+0x8: orr r0, r0, r2
netbsd:softint_trigger+0xc: str r0, [r3, #0x184]
netbsd:softint_trigger+0x10: bx r14
netbsd:softint_init_md: mov r12, r13
netbsd:softint_init_md+0x4: push {r4-r8, r11-r12, r14-r15}
netbsd:softint_init_md+0x8: sub r11, r12, #0x00000004
netbsd:softint_init_md+0xc: sub r13, r13, #0x0000000c
netbsd:softint_init_md+0x10: mov r5, r0
netbsd:softint_init_md+0x14: mov r4, r1
netbsd:softint_init_md+0x18: mov r6, r1, lsl #2
netbsd:softint_init_md+0x1c: mov r8, r2
netbsd:softint_init_md+0x20: ldr r7, [r0, #0x00c]
netbsd:softint_init_md+0x24: add r7, r7, r6
netbsd:softint_init_md+0x28: ldr r3, [r7, #0x174]
db{0}> ps/t 0t230
usage: show all procs [/a] [/l] [/n] [/w]
/a =3D=3D show process address info
/l =3D=3D show LWP info [default]
/n =3D=3D show normal process info
/w =3D=3D show process wait/emul info
db{0}> bt/t 0t230
trace: pid 230 lid 1 at 0xbaccdd4c
0xbaccdd4c: netbsd:mi_switch+0x10
0xbaccdd7c: netbsd:sleepq_block+0xb4
0xbaccddbc: netbsd:turnstile_block+0x3e8
0xbaccde1c: netbsd:mutex_enter+0x220
0xbaccde3c: netbsd:sosetlock+0x58
0xbaccde6c: netbsd:tcp_attach_wrapper+0x30
0xbaccde9c: netbsd:socreate+0x158
0xbaccdee4: netbsd:fsocreate+0xac
0xbaccdf0c: netbsd:sys___socket30+0x30
0xbaccdf7c: netbsd:syscall+0x88
0xbaccdfac: netbsd:swi_handler+0x98
db{0}> bt/a bacfa060
trace: pid 0 lid 53 at 0xbaccbf1c
0xbaccbf1c: netbsd:mi_switch+0x10
0xbaccbf4c: netbsd:sleepq_block+0x16c
0xbaccbf84: netbsd:cv_timedwait+0x108
0xbaccbfac: netbsd:usb_event_thread+0xf0
db{0}>=20
From: Nick Hudson <nick.hudson@gmx.co.uk>
To: gnats-bugs@NetBSD.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Thu, 3 Dec 2015 07:32:03 +0000
On 12/3/2015 5:30 AM, Michael Plass wrote:
> The following reply was made to PR kern/50491; it has been noted by GNATS.
>
> From: Michael Plass <mfpnb@plass-family.net>
> To: gnats-bugs@NetBSD.org
> Cc: Michael Plass <mfpnb@plass-family.net>
> Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
> Date: Wed, 2 Dec 2015 21:26:11 -0800
>
> Nick,
>
> I saw one of the 'usbd_do_request: not in process context' messages go by
> (actually while still coming up to multiuser mode), but apparently DEBUG was
> not defined, so the ASSERT_SLEEPABLE() was a NOP. I've rebuilt with a call to
> assert_sleepable() instead, and I'll run with that.
Oops. Any reason to not define DEBUG? assert_sleepable should do, but
they more checks the better.
> PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
> 230 1 3 0 0 bacfab60 cleanup tstile
> 2583 1 3 3 0 ba46a0c0 sshd tstile
> 0 31 3 3 200 bada4880 softclk/3 tstile
> 0 5 3 0 200 baf05340 softclk/0 tstile
> 0 3 3 0 200 baf058c0 softnet/0 tstile
Backtraces from these might help, but see below...
> db{0}> bt/t 0t230
> trace: pid 230 lid 1 at 0xbaccdd4c
> 0xbaccdd4c: netbsd:mi_switch+0x10
> 0xbaccdd7c: netbsd:sleepq_block+0xb4
> 0xbaccddbc: netbsd:turnstile_block+0x3e8
> 0xbaccde1c: netbsd:mutex_enter+0x220
> 0xbaccde3c: netbsd:sosetlock+0x58
> 0xbaccde6c: netbsd:tcp_attach_wrapper+0x30
> 0xbaccde9c: netbsd:socreate+0x158
> 0xbaccdee4: netbsd:fsocreate+0xac
> 0xbaccdf0c: netbsd:sys___socket30+0x30
> 0xbaccdf7c: netbsd:syscall+0x88
> 0xbaccdfac: netbsd:swi_handler+0x98
Blocked on softnet_lock in sosetlock
x/x softnet_lock should tell us who owns it. Get a backtrace from the
offending lwp.
Nick
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Wed, 2 Dec 2015 22:13:41 -0800
Nick,
It didn't take long to hit it this time...
- Michael
Setting date via ntp.
panic: assert_sleepable: softint caller=0x802e2014
cpu2: Begin traceback...
0xbada3c3c: netbsd:db_panic+0xc
0xbada3c6c: netbsd:vpanic+0x1b0
0xbada3c84: netbsd:snprintf
0xbada3cbc: netbsd:assert_sleepable+0xb4
0xbada3d0c: netbsd:usbd_do_request_flags_pipe+0x28
0xbada3d34: netbsd:usbd_do_request+0x38
0xbada3d64: netbsd:smsc_write_reg+0x60
0xbada3d8c: netbsd:smsc_setmulti+0x100
0xbada3dbc: netbsd:smsc_ioctl+0x124
0xbada3e64: netbsd:if_mcast_op+0x50
0xbada3eb4: netbsd:in6_delmulti+0x154
0xbada3ecc: netbsd:in6_leavegroup+0x20
0xbada3ef4: netbsd:in6_purgeaddr+0x6c
0xbada3f2c: netbsd:nd6_timer+0x108
0xbada3f64: netbsd:callout_softclock+0x194
0xbada3fac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x805fbf54
cpu2: End traceback...
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Thu, 3 Dec 2015 21:39:08 -0800
Nick,
I built with DEBUG, and it panics quite early.
- Michael
NetBSD/evbarm (rpi) booting ...
[ Kernel symbol table missing! ]
Loaded initial symtab at 0x804aaf88, strtab at 0x804efad8, # entries =
17570
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, =
2005,
2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015
The NetBSD Foundation, Inc. All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
NetBSD 7.0 (RPI2_DEBUG) #0: Thu Dec 3 21:14:26 PST 2015
=
michael@home.plass-family.net:/home/michael/NetBSD-7.0/build/usr/src/sys/a=
rch/evbarm/compile/obj/RPI2_DEBUG
total memory =3D 944 MB
avail memory =3D 928 MB
sysctl_createv: sysctl_create(machine_arch) returned 17
kern.module.path=3D/stand/evbarm/7.0/modules
mainbus0 (root)
cpu0 at mainbus0 core 0: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu0: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu0: 32KB/32B 2-way L1 VIPT Instruction cache
cpu0: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu0: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp0 at cpu0: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
cpu1 at mainbus0 core 1
cpu2 at mainbus0 core 2
cpu3 at mainbus0 core 3
obio0 at mainbus0
bcmicu0 at obio0: Multiprocessor
armgtmr0 at obio0: ARMv7 Generic 64-bit Timer (19200 kHz)
armgtmr0: interrupting on irq 3
bcmmbox0 at obio0: VC mailbox
vcmbox0 at bcmmbox0
vchiq0 at obio0 intr 194: BCM2835 VCHIQ
bcmpm0 at obio0: Power management, Reset and Watchdog controller
bcmdmac0 at obio0: DMA0 DMA2 DMA4 DMA5 DMA8 DMA9 DMA10
bcmrng0 at obio0: RNG
plcom0 at obio0 intr 185
plcom0: txfifo disabled
plcom0: console
genfb0 at obio0
wsdisplay0 at genfb0 kbdmux 1
sdhc0 at obio0 intr 190: SDHC controller
sdhc0: interrupting on intr 190
dwctwo0 at obio0 intr 137: USB controller
bcmspi0 at obio0 intr 182: SPI
spi0 at bcmspi0: SPI bus
bsciic0 at obio0 intr 181: BSC0
iic0 at bsciic0: I2C bus
bsciic1 at obio0 intr 181: BSC1
iic1 at bsciic1: I2C bus
bcmgpio0 at obio0: GPIO [0...31]
gpio0 at bcmgpio0: 32 pins
bcmgpio1 at obio0: GPIO [32...53]
gpio1 at bcmgpio1: 22 pins
usb0 at dwctwo0: USB revision 2.0
cpu2: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu2: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu2: 32KB/32B 2-way L1 VIPT Instruction cache
cpu2: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu2: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp2 at cpu2: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
cpu3panic: :a s6s0e0r tM_Hszl eCeopratbelxe-:A 7i drl0ep 5c =
a(lCloerrt=3De0xx 8V07)A3 7c1o8r4e
=20
cpu3: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu3: 32KB/32B 2-way L1 VIPT Instruction cache
cpu3: 32KB/64B 4-way write-back-lockinSgt-oCp pLe1d PiInP Tp iDda t0a. =
2c2a c(hsey
tcepmu)3 :a t512KB/ 6n4eBt b8s-dw:acyp uw_rDietbeu-gtgherro+u0gxh4 :L 2 =
P I PeT Ubnxi f i e d cra1c4h
d
bv{f2p}3> at cpu3: NEON MPE (VFP 3.0+), rounding, NaN propagation, =
denormals
cpu1: 600 MHz Cortex-A7 r0p5 (Cortex V7A core)
cpu1: DC enabled IC enabled WB disabled EABT branch prediction enabled
cpu1: 32KB/32B 2-way L1 VIPT Instruction cache
cpu1: 32KB/64B 4-way write-back-locking-C L1 PIPT Data cache
cpu1: 512KB/64B 8-way write-through L2 PIPT Unified cache
vfp1 at cpu1: NEON MPE (VFP 3.0+), rounding, NaN propagation, denormals
db{2}> bt =20
0x8060be84: netbsd:vpanic+0xc
0x8060be9c: netbsd:snprintf
0x8060bed4: netbsd:assert_sleepable+0xb4
0x8060bef4: netbsd:percpu_alloc+0x18
0x8060bf2c: netbsd:pic_add+0xc4
0x8060bf54: netbsd:bcm2836mp_intr_init+0x38
0x8060bf6c: netbsd:bcm2836_cpu_hatch+0x14
0x8060bf94: netbsd:cpu_hatch+0x1a4
Bad frame pointer: 0x8060be34
db{2}>=20
From: Nick Hudson <nick.hudson@gmx.co.uk>
To: gnats-bugs@NetBSD.org, skrll@NetBSD.org, gnats-admin@netbsd.org,
netbsd-bugs@netbsd.org, mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Fri, 4 Dec 2015 07:15:59 +0000
On 12/4/2015 7:00 AM, Michael Plass wrote:
> The following reply was made to PR kern/50491; it has been noted by GNATS.
>
> From: Michael Plass <mfpnb@plass-family.net>
> To: gnats-bugs@NetBSD.org
> Cc:
> Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
> Date: Thu, 3 Dec 2015 21:39:08 -0800
>
> Nick,
>
> I built with DEBUG, and it panics quite early.
>
> db{2}> bt =20
> 0x8060be84: netbsd:vpanic+0xc
> 0x8060be9c: netbsd:snprintf
> 0x8060bed4: netbsd:assert_sleepable+0xb4
> 0x8060bef4: netbsd:percpu_alloc+0x18
> 0x8060bf2c: netbsd:pic_add+0xc4
> 0x8060bf54: netbsd:bcm2836mp_intr_init+0x38
> 0x8060bf6c: netbsd:bcm2836_cpu_hatch+0x14
> 0x8060bf94: netbsd:cpu_hatch+0x1a4
> Bad frame pointer: 0x8060be34
> db{2}>=20
>
>
Apprarently I forgot to get this change pulled up
http://cvsweb.netbsd.org/bsdweb.cgi/src/sys/kern/kern_lock.c.diff?r1=1.155&r2=1.156
I'll fix that.
Nick
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc: Michael Plass <mfpnb@plass-family.net>
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Fri, 4 Dec 2015 00:17:39 -0800
On Dec 2, 2015, at 11:35 PM, Nick Hudson wrote:
>>
>> PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
>> 230 1 3 0 0 bacfab60 cleanup tstile
>
>
>> 2583 1 3 3 0 ba46a0c0 sshd tstile
>
>> 0 31 3 3 200 bada4880 softclk/3 tstile
>
>
>> 0 5 3 0 200 baf05340 softclk/0 tstile
>
>> 0 3 3 0 200 baf058c0 softnet/0 tstile
>
>
> Backtraces from these might help, but see below...
This time I have:
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
4207 1 3 0 80 b7c643e0 sh ttyout
2014 1 3 0 80 bac1b6a0 sh wait
4858 1 3 0 0 b5a226c0 mdnsd tstile
1156 1 3 0 0 b5a22980 mdnsd tstile
1512 1 3 2 0 b90b2ec0 mdnsd tstile
422 1 3 0 0 b9dbbc60 mdnsd tstile
2891 1 3 0 0 bacfa060 mdnsd tstile
4344 1 3 0 0 ba2bf6c0 mdnsd tstile
930 1 3 0 0 b7c659e0 mdnsd tstile
242 1 3 0 0 b7c651a0 mdnsd tstile
2591 1 3 0 0 b7c64ee0 mdnsd tstile
169 1 3 0 0 b7c64960 mdnsd tstile
4268 1 3 0 0 b7c646a0 mdnsd tstile
4054 1 3 1 0 b5a22f00 mdnsd tstile
3260 1 3 0 0 b7c64c20 mdnsd tstile
1160 1 3 0 0 b7c65460 mdnsd tstile
3779 1 3 0 0 b7c64120 mdnsd usbxfer
3643 1 3 3 80 b5a23a00 find ttyout
2903 1 3 3 80 b9dbb420 sh wait
2702 1 3 1 0 b9dbaea0 sshd tstile
706 1 3 1 80 b9dbb160 sshd select
82 1 3 0 80 bac1b3e0 sh wait
80 1 3 0 80 bac1a8e0 su wait
71 1 3 0 80 b9dbb6e0 sh wait
70 1 3 0 0 b9dbb9a0 sshd tstile
73 1 3 1 80 b9dba660 sshd select
2667 1 3 3 80 bacfae20 getty ttyraw
2559 1 3 2 80 b90b2100 cron nanoslp
1517 1 3 0 80 b7c65720 inetd kqueue
2196 1 3 1 80 b90b3700 qmgr kqueue
2129 1 3 0 80 b9dba0e0 pickup kqueue
2005 1 3 1 80 b7c65ca0 master kqueue
1785 1 3 1 80 bac1a360 sshd select
1725 1 3 3 80 b90b3c80 ntpd pause
1662 1 3 0 80 ba2bf400 devpubd devmon
740 1 3 1 80 bac1a620 syslogd kqueue
613 1 3 3 80 ba2bfc40 dhcpcd select
1 1 3 3 80 bacfa320 init wait
0 64 3 1 200 bacfa8a0 physiod physiod
0 63 3 1 280 bac1b960 VCHIQka-0 lnxcmplt
0 62 3 0 200 bac1bc20 aiodoned aiodoned
0 61 3 1 200 bacc0080 ioflush syncer
0 60 3 1 200 bacc0340 pgdaemon pgdaemon
0 59 3 1 280 bacc0600 vcaudio data
0 58 3 1 280 bacc08c0 VCHIQs-0 semacv
0 57 3 1 280 bacc0b80 VCHIQr-0 semacv
0 56 3 1 280 bacc0e40 VCHIQ-0 semacv
0 53 3 1 200 bacc1100 usb0 usbevt
0 52 3 1 200 bacc1c00 unpgc unpgc
0 50 3 1 200 bacc1940 vmem_rehash vmem_rehash
0 49 3 2 200 bacc13c0 sdmmc0 mmctaskq
0 48 3 0 200 bacc1680 vcmbox0 vcmbox0
0 39 3 3 200 bacfb0e0 usbtask-dr usbxfer
0 38 3 0 200 bacfb3a0 usbtask-hc usbtsk
0 37 3 0 200 bacfb660 dwc2 dwc2
0 36 3 1 200 bacfb920 iic1 iicintr
0 35 3 0 200 bacfbbe0 iic0 iicintr
0 34 3 0 200 bada4040 sysmon smtaskq
0 33 3 3 200 bada4300 xcall/3 xcall
0 32 1 3 200 bada45c0 softser/3
0 31 1 3 200 bada4880 softclk/3
0 30 1 3 200 bada4b40 softbio/3
0 29 1 3 200 bada4e00 softnet/3
0 > 28 7 3 201 bada50c0 idle/3
0 27 3 2 200 bada5380 xcall/2 xcall
0 26 1 2 200 bada5640 softser/2
0 25 1 2 200 bada5900 softclk/2
0 24 1 2 200 bada5bc0 softbio/2
0 23 1 2 200 badd4020 softnet/2
0 > 22 7 2 201 badd42e0 idle/2
0 21 3 1 200 badd45a0 xcall/1 xcall
0 20 1 1 200 badd4860 softser/1
0 19 3 1 200 badd4b20 softclk/1 tstile
0 18 1 1 200 badd4de0 softbio/1
0 17 1 1 200 badd50a0 softnet/1
0 > 16 7 1 201 badd5360 idle/1
0 15 3 0 200 badd5620 pmfsuspend pmfsuspend
0 14 3 2 200 badd58e0 pmfevent pmfevent
0 13 3 0 200 badd5ba0 sopendfree sopendfr
0 12 3 3 200 baf04000 nfssilly nfssilly
0 11 3 3 200 baf042c0 cachegc cachegc
0 10 3 0 200 baf04580 vrele vrele
0 9 3 0 200 baf04840 vdrain vdrain
0 8 3 0 200 baf04b00 modunload mod_unld
0 7 3 0 200 baf04dc0 xcall/0 xcall
0 6 1 0 200 baf05080 softser/0
0 5 1 0 200 baf05340 softclk/0
0 4 1 0 200 baf05600 softbio/0
0 3 3 0 200 baf058c0 softnet/0 tstile
0 > 2 7 0 201 baf05b80 idle/0
0 1 3 0 200 805718c0 swapper uvm
db{0}> bt/a b5a226c0
trace: pid 4858 lid 1 at 0xb4f83d5c
0xb4f83d5c: netbsd:mi_switch+0x10
0xb4f83d8c: netbsd:sleepq_block+0xb4
0xb4f83dcc: netbsd:turnstile_block+0x3e8
0xb4f83e2c: netbsd:mutex_enter+0x220
0xb4f83e4c: netbsd:sosetlock+0x58
0xb4f83e6c: netbsd:udp_attach_wrapper+0x30
0xb4f83e9c: netbsd:socreate+0x158
0xb4f83ee4: netbsd:fsocreate+0xac
0xb4f83f0c: netbsd:sys___socket30+0x30
0xb4f83f7c: netbsd:syscall+0x88
0xb4f83fac: netbsd:swi_handler+0x98
(other 'mdnsd tstile' threads are similar)
# 3779 1 3 0 0 b7c64120 mdnsd usbxfer
db{0}> bt/a b7c64120
trace: pid 3779 lid 1 at 0xb5895b6c
0xb5895b6c: netbsd:mi_switch+0x10
0xb5895b9c: netbsd:sleepq_block+0xb4
0xb5895bcc: netbsd:cv_wait+0x104
0xb5895bfc: netbsd:usbd_transfer+0x23c
0xb5895c4c: netbsd:usbd_do_request_flags_pipe+0xd8
0xb5895c74: netbsd:usbd_do_request+0x38
0xb5895ca4: netbsd:smsc_write_reg+0x60
0xb5895cd4: netbsd:smsc_ioctl+0x124
0xb5895d7c: netbsd:if_mcast_op+0x50
0xb5895db4: netbsd:in_addmulti+0xc0
0xb5895e1c: netbsd:ip_ctloutput+0xa4c
0xb5895e4c: netbsd:udp_ctloutput+0x94
0xb5895e6c: netbsd:udp_ctloutput_wrapper+0x30
0xb5895ed4: netbsd:sosetopt+0x6c
0xb5895f0c: netbsd:sys_setsockopt+0x84
0xb5895f7c: netbsd:syscall+0x88
0xb5895fac: netbsd:swi_handler+0x98
# 2702 1 3 1 0 b9dbaea0 sshd tstile
db{0}> bt/a b9dbaea0
trace: pid 2702 lid 1 at 0xb9f8dc24
0xb9f8dc24: netbsd:mi_switch+0x10
0xb9f8dc54: netbsd:sleepq_block+0xb4
0xb9f8dc94: netbsd:turnstile_block+0x3e8
0xb9f8dcf4: netbsd:mutex_enter+0x220
0xb9f8dd1c: netbsd:sopoll+0x24
0xb9f8ddac: netbsd:sel_do_scan+0x304
0xb9f8debc: netbsd:selcommon.part.2+0x12c
0xb9f8df0c: netbsd:sys___select50+0x84
0xb9f8df7c: netbsd:syscall+0x88
0xb9f8dfac: netbsd:swi_handler+0x98
# 0 39 3 3 200 bacfb0e0 usbtask-dr usbxfer
db{0}> bt/a bacfb0e0
trace: pid 0 lid 39 at 0xbacedd7c
0xbacedd7c: netbsd:mi_switch+0x10
0xbaceddac: netbsd:sleepq_block+0xb4
0xbacedddc: netbsd:cv_wait+0x104
0xbacede0c: netbsd:usbd_transfer+0x23c
0xbacede5c: netbsd:usbd_do_request_flags_pipe+0xd8
0xbacede84: netbsd:usbd_do_request+0x38
0xbacedeb4: netbsd:smsc_read_reg+0x60
0xbacededc: netbsd:smsc_wait_for_bits+0x4c
0xbacedf04: netbsd:smsc_miibus_readreg+0x4c
0xbacedf2c: netbsd:mii_phy_tick+0x68
0xbacedf4c: netbsd:ukphy_service+0xac
0xbacedf64: netbsd:mii_tick+0x54
0xbacedf7c: netbsd:smsc_tick_task+0x34
0xbacedfac: netbsd:usb_task_thread+0x10c
# 0 19 3 1 200 badd4b20 softclk/1 tstile
db{0}> bt/a badd4b20
trace: pid 0 lid 19 at 0xbadb9e2c
0xbadb9e2c: netbsd:mi_switch+0x10
0xbadb9e5c: netbsd:sleepq_block+0xb4
0xbadb9e9c: netbsd:turnstile_block+0x3e8
0xbadb9efc: netbsd:mutex_enter+0x220
0xbadb9f14: netbsd:frag6_fasttimo+0x24
0xbadb9f2c: netbsd:pffasttimo+0x58
0xbadb9f64: netbsd:callout_softclock+0x194
0xbadb9fac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x805f9f54
# 0 3 3 0 200 baf058c0 softnet/0 tstile
db{0}> bt/a baf058c0
trace: pid 0 lid 3 at 0xbaeffe24
0xbaeffe24: netbsd:mi_switch+0x10
0xbaeffe54: netbsd:sleepq_block+0xb4
0xbaeffe94: netbsd:turnstile_block+0x3e8
0xbaeffef4: netbsd:mutex_enter+0x220
0xbaefff64: netbsd:ipintr+0x3c
0xbaefffac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0xba987fac
>
>> db{0}> bt/t 0t230
>> trace: pid 230 lid 1 at 0xbaccdd4c
>> 0xbaccdd4c: netbsd:mi_switch+0x10
>> 0xbaccdd7c: netbsd:sleepq_block+0xb4
>> 0xbaccddbc: netbsd:turnstile_block+0x3e8
>> 0xbaccde1c: netbsd:mutex_enter+0x220
>> 0xbaccde3c: netbsd:sosetlock+0x58
>> 0xbaccde6c: netbsd:tcp_attach_wrapper+0x30
>> 0xbaccde9c: netbsd:socreate+0x158
>> 0xbaccdee4: netbsd:fsocreate+0xac
>> 0xbaccdf0c: netbsd:sys___socket30+0x30
>> 0xbaccdf7c: netbsd:syscall+0x88
>> 0xbaccdfac: netbsd:swi_handler+0x98
>
> Blocked on softnet_lock in sosetlock
>
> x/x softnet_lock should tell us who owns it. Get a backtrace from the
> offending lwp.
Unfortunately, softnet_lock does not seem to point to a valid LWP.
Could a thread have exited while holding the lock?
db{0}> x/x softnet_lock
netbsd:softnet_lock: bafadf40
db{0}> bt/a bafadf40
trace: pid 0 lid 7235937 at 0xbaaaab2a
0xbaaaab2a: 8855e086
From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Fri, 4 Dec 2015 08:28:55 +0000
On 12/04/15 08:20, Michael Plass wrote:
> The following reply was made to PR kern/50491; it has been noted by GNATS.
> db{0}> x/x softnet_lock
> netbsd:softnet_lock: bafadf40
> db{0}> bt/a bafadf40
> trace: pid 0 lid 7235937 at 0xbaaaab2a
> 0xbaaaab2a: 8855e086
>
Oops, 0xbafadf40 is the address of softnet_lock
x/x 0xbafadf40 should give you the lwp pointer
Nick
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Fri, 4 Dec 2015 08:34:49 -0800
On Dec 4, 2015, at 2:05 AM, Nick Hudson wrote:
> Oops, 0xbafadf40 is the address of softnet_lock
db{0}> x/x softnet_lock
netbsd:softnet_lock: bafadf40
db{0}> x/x bafadf40
bafadf40: ba526662
db{0}> x/x bafadf40,4
bafadf40: ba526662 5aa3c85d e baaaaaaa
(hmm - not aligned, can't be good)
db{0}> bt/a ba526662
address 0xba48 is invalid
trace: pid 0 lid 0
Non-emulated page fault with intr_depth > 0
Fatal kernel mode data abort: 'Translation Fault (S)'
trapframe: 0x805f7658
FSR=00000005, FAR=1fb0b912, spsr=60000013
r0 =803d6e48, r1 =00000010, r2 =00000000, r3 =1fb0b906
r4 =ba526662, r5 =80238604, r6 =80238468, r7 =00000001
r8 =0000ffff, r9 =8057d378, r10=00000000, r11=805f7b54
r12=805f75e0, ssp=805f76a8, slr=80238010, pc =8004e894
Faulted in DDB; continuing...
From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Fri, 4 Dec 2015 16:43:30 +0000
On 12/04/15 16:35, Michael Plass wrote:
> The following reply was made to PR kern/50491; it has been noted by GNATS.
>
> From: Michael Plass <mfpnb@plass-family.net>
> To: gnats-bugs@NetBSD.org
> Cc:
> Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
> Date: Fri, 4 Dec 2015 08:34:49 -0800
>
> On Dec 4, 2015, at 2:05 AM, Nick Hudson wrote:
>
> > Oops, 0xbafadf40 is the address of softnet_lock
>
> db{0}> x/x softnet_lock
> netbsd:softnet_lock: bafadf40
> db{0}> x/x bafadf40
> bafadf40: ba526662
need to strip off the bottom two bits
http://nxr.netbsd.org/xref/src/sys/sys/mutex.h#161
Is 0xba526660 from a new lockup as I don't see it in the list of lwps in
the PR?
Nick
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Fri, 4 Dec 2015 19:24:21 -0800
On Dec 4, 2015, at 10:20 AM, Nick Hudson wrote:
>=20
> Is 0xba526660 from a new lockup as I don't see it in the list of lwps =
in=20
> the PR?
>=20
Yes, it was a new instance. But I still have the ps list for that, and =
it turns out to be:
2193 1 3 3 0 ba526660 mdnsd usbxfer
and we've seen the stack for that one before.
I also had tracing on as before; the last little bit looks like:
usbd_transfer: xfer=3D0xbacb9d40, flags=3D0x2, pipe=3D0xbafa0780, =
running=3D1
usbd_dump_queue: pipe=3D0xbafa0780
xfer=3D0xbacb98c0
usb_allocmem: use frag=3D0xc90acd80 size=3D4
dwc2_device_ctrl_transfer:=20
usb_insert_transfer: pipe=3D0xbafa0780 running=3D1 timeout=3D5000
dwc2_device_start: xfer=3D0xbacb98c0 pipe=3D0xbafa0780
dwctwo0: urb=3D0x81365588, xfer=3D0x0
usb_schedsoftintr: polling=3D0
usb_schedsoftintr: polling=3D0
- Michael
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Fri, 4 Dec 2015 23:21:46 -0800
Nick,
I rebuilt with options LOCKDEBUG, and got this. I'll leave it in ddb for =
now in case you want me to poke around some more. - Michael
Stopped in pid 0.2 (system) at netbsd:cpu_Debugger+0x4: bx =
r14
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
5484 1 3 0 80 b7a64c00 sleep nanoslp
4159 1 3 0 0 b72379e0 mdnsd usbxfer
3675 1 3 2 80 ba6bbc40 find ttyout
3141 1 3 3 80 b7a65c80 sh wait
3735 1 3 2 40000 b7a659c0 sshd tstile
3028 1 3 3 80 b7a64680 sshd select
40 1 3 0 80 ba038ea0 sh wait
41 1 3 1 80 baceae20 su wait
2518 1 3 1 80 ba6ba0c0 sh wait
2202 1 3 2 80 b7a65700 sshd select
2460 1 3 2 80 ba0380e0 sshd select
2314 1 3 2 80 bab83960 getty ttyraw
2264 1 3 2 80 bacea8a0 cron nanoslp
2285 1 3 0 80 b7a64ec0 inetd kqueue
2077 1 3 2 80 ba6babc0 qmgr kqueue
2206 1 3 1 80 ba039c60 pickup kqueue
2027 1 3 0 80 b7a65180 master kqueue
1841 1 3 3 80 bab82360 sshd select
1582 1 3 1 1000000 ba038be0 ntpd tstile
1572 1 3 0 80 bacea320 devpubd devmon
565 1 3 3 80 ba6bb400 dhcpcd select
1 1 3 2 80 baceab60 init wait
0 64 3 2 200 bacb0e40 physiod physiod
0 63 3 2 280 bab83c20 VCHIQka-0 =
lnxcmplt
0 62 3 2 200 bacb0080 aiodoned =
aiodoned
0 61 3 0 200 bacea5e0 ioflush syncer
0 60 3 2 200 bacb1c00 pgdaemon =
pgdaemon
0 59 3 2 280 bacb0340 vcaudio data
0 58 3 2 280 bacb0600 VCHIQs-0 semacv
0 57 3 2 280 bacb08c0 VCHIQr-0 semacv
0 56 3 2 280 bacb0b80 VCHIQ-0 semacv
0 53 3 3 200 bacb1100 usb0 usbevt
0 51 3 3 200 bacea060 unpgc unpgc
0 50 3 1 200 bacb1940 vmem_rehash =
vmem_rehash
0 49 3 3 200 bacb13c0 sdmmc0 =
mmctaskq
0 48 3 2 200 bacb1680 vcmbox0 vcmbox0
0 39 3 1 200 baceb0e0 usbtask-dr usbxfer
0 38 3 0 200 baceb3a0 usbtask-hc usbtsk
0 37 3 0 200 baceb660 dwc2 dwc2
0 36 3 3 200 baceb920 iic1 iicintr
0 35 3 0 200 bacebbe0 iic0 iicintr
0 34 3 0 200 bad9c040 sysmon smtaskq
0 33 3 3 200 bad9c300 xcall/3 xcall
0 32 1 3 200 bad9c5c0 softser/3
0 31 3 3 200 bad9c880 softclk/3 tstile
0 30 1 3 200 bad9cb40 softbio/3
0 29 1 3 200 bad9ce00 softnet/3
0 > 28 7 3 201 bad9d0c0 idle/3
0 27 3 2 200 bad9d380 xcall/2 xcall
0 26 1 2 200 bad9d640 softser/2
0 25 3 2 200 bad9d900 softclk/2 tstile
0 24 1 2 200 bad9dbc0 softbio/2
0 23 1 2 200 badcc020 softnet/2
0 > 22 7 2 201 badcc2e0 idle/2
0 21 3 1 200 badcc5a0 xcall/1 xcall
0 20 1 1 200 badcc860 softser/1
0 19 1 1 200 badccb20 softclk/1
0 18 1 1 200 badccde0 softbio/1
0 17 1 1 200 badcd0a0 softnet/1
0 > 16 7 1 201 badcd360 idle/1
0 15 3 2 200 badcd620 pmfsuspend =
pmfsuspend
0 14 3 1 200 badcd8e0 pmfevent =
pmfevent
0 13 3 0 200 badcdba0 sopendfree =
sopendfr
0 12 3 0 200 baefc000 nfssilly =
nfssilly
0 11 3 3 200 baefc2c0 cachegc cachegc
0 10 3 2 200 baefc580 vrele vrele
0 9 3 2 200 baefc840 vdrain vdrain
0 8 3 0 200 baefcb00 modunload =
mod_unld
0 7 3 0 200 baefcdc0 xcall/0 xcall
0 6 1 0 200 baefd080 softser/0
0 5 3 0 200 baefd340 softclk/0 tstile
0 4 1 0 200 baefd600 softbio/0
0 3 3 0 200 baefd8c0 softnet/0 tstile
0 > 2 7 0 201 baefdb80 idle/0
0 1 3 3 200 805718c0 swapper uvm
db{0}> x/x softnet_lock
netbsd:softnet_lock: bafadf40
db{0}> show lock bafadf40
lock address : 0x00000000bafadf40 type : sleep/adaptive
initialized : 0x0000000080154ee0
shared holds : 0 exclusive: 1
shares wanted: 0 exclusive: 6
current cpu : 0 last held: 0
current lwp : 0x00000000baefdb80 last held: 0x00000000b72379e0
last locked* : 0x00000000802c1a3c unlocked : 0x00000000802c1a8c
owner field : 0x00000000b72379e0 wait/spin: 1/0
Turnstile chain at 0x8057a340.
=3D> Turnstile at 0xbaefbf48 (wrq=3D0xbaefbf58, rdq=3D0xbaefbf60).
=3D> 0 waiting readers:
=3D> 6 waiting writers: 0xbaefd8c0 0xbad9c880 0xbaefd340 0xbad9d900 =
0xba038be0 0xb
7a659c0
db{0}> bt/a b72379e0
trace: pid 4159 lid 1 at 0xb69cfae4
0xb69cfae4: netbsd:mi_switch+0x10
0xb69cfb14: netbsd:sleepq_block+0xb4
0xb69cfb4c: netbsd:cv_wait+0x130
0xb69cfb7c: netbsd:usbd_transfer+0x23c
0xb69cfbcc: netbsd:usbd_do_request_flags_pipe+0xd8
0xb69cfbf4: netbsd:usbd_do_request+0x38
0xb69cfc24: netbsd:smsc_write_reg+0x60
0xb69cfc4c: netbsd:smsc_setmulti+0x110
0xb69cfc7c: netbsd:smsc_ioctl+0x124
0xb69cfd24: netbsd:if_mcast_op+0x50
0xb69cfd74: netbsd:in6_addmulti+0x1ac
0xb69cfd9c: netbsd:in6_joingroup+0x44
0xb69cfe24: netbsd:ip6_ctloutput+0x132c
0xb69cfe4c: netbsd:udp6_ctloutput+0x9c
0xb69cfe6c: netbsd:udp6_ctloutput_wrapper+0x30
0xb69cfed4: netbsd:sosetopt+0x6c
0xb69cff0c: netbsd:sys_setsockopt+0x84
0xb69cff7c: netbsd:syscall+0x88
0xb69cffac: netbsd:swi_handler+0x98
db{0}> bt/a 0xbaefd8c0
trace: pid 0 lid 3 at 0xbaef7e24
0xbaef7e24: netbsd:mi_switch+0x10
0xbaef7e54: netbsd:sleepq_block+0xb4
0xbaef7e94: netbsd:turnstile_block+0x318
0xbaef7ef4: netbsd:mutex_enter+0x264
0xbaef7f64: netbsd:ipintr+0x3c
0xbaef7fac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x805fff6c
db{0}> bt/a 0xbad9c880
trace: pid 0 lid 31 at 0xbad87e2c
0xbad87e2c: netbsd:mi_switch+0x10
0xbad87e5c: netbsd:sleepq_block+0xb4
0xbad87e9c: netbsd:turnstile_block+0x318
0xbad87efc: netbsd:mutex_enter+0x264
0xbad87f14: netbsd:frag6_fasttimo+0x24
0xbad87f2c: netbsd:pffasttimo+0x58
0xbad87f64: netbsd:callout_softclock+0x194
0xbad87fac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x80605f54
db{0}> bt/a 0xbaefd340
trace: pid 0 lid 5 at 0xbaef3e24
0xbaef3e24: netbsd:mi_switch+0x10
0xbaef3e54: netbsd:sleepq_block+0xb4
0xbaef3e94: netbsd:turnstile_block+0x318
0xbaef3ef4: netbsd:mutex_enter+0x264
0xbaef3f2c: netbsd:nd6_timer+0x58
0xbaef3f64: netbsd:callout_softclock+0x194
0xbaef3fac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x805fff6c
db{0}> bt/a 0xbad9d900
trace: pid 0 lid 25 at 0xbad9be1c
0xbad9be1c: netbsd:mi_switch+0x10
0xbad9be4c: netbsd:sleepq_block+0xb4
0xbad9be8c: netbsd:turnstile_block+0x318
0xbad9beec: netbsd:mutex_enter+0x264
0xbad9bf2c: netbsd:tcp_timer_rexmt+0x24
0xbad9bf64: netbsd:callout_softclock+0x194
0xbad9bfac: netbsd:softint_dispatch+0xd4
Bad frame pointer: 0x80603f54
db{0}> bt/a 0xba038be0
trace: pid 1582 lid 1 at 0xb9693c5c
0xb9693c5c: netbsd:mi_switch+0x10
0xb9693c8c: netbsd:sleepq_block+0xb4
0xb9693ccc: netbsd:turnstile_block+0x318
0xb9693d2c: netbsd:mutex_enter+0x264
0xb9693dbc: netbsd:sosend+0x38
0xb9693e74: netbsd:do_sys_sendmsg_so.isra.2+0x230
0xb9693eb4: netbsd:do_sys_sendmsg+0x90
0xb9693f0c: netbsd:sys_sendto+0x64
0xb9693f7c: netbsd:syscall+0x88
0xb9693fac: netbsd:swi_handler+0x98
db{0}> bt/a 0xb7a659c0
trace: pid 3735 lid 1 at 0xb7aa3c24
0xb7aa3c24: netbsd:mi_switch+0x10
0xb7aa3c54: netbsd:sleepq_block+0xb4
0xb7aa3c94: netbsd:turnstile_block+0x318
0xb7aa3cf4: netbsd:mutex_enter+0x264
0xb7aa3d1c: netbsd:sopoll+0x24
0xb7aa3dac: netbsd:sel_do_scan+0x304
0xb7aa3ebc: netbsd:selcommon.part.2+0x12c
0xb7aa3f0c: netbsd:sys___select50+0x84
0xb7aa3f7c: netbsd:syscall+0x88
0xb7aa3fac: netbsd:swi_handler+0x98
db{0}> callout
hardclock_ticks now: 43145
ticks wheel arg func
-2231 -1/-256 0 rt_timer_timer
-2231 -1/-256 bad6680c vcons_intr
-2131 -1/-256 0 if_slowtimo
-2131 -1/-256 0 nd6_timer
-2225 -1/-256 0 sched_balance
-2221 -1/-256 b7a64c00 sleepq_timeout
-2147 -1/-256 bacebbe0 sleepq_timeout
-2138 -1/-256 bacea5e0 sleepq_timeout
-1144 -1/-256 baf9c148 sme_events_check
-2147 -1/-256 baefc580 sleepq_timeout
-2145 -1/-256 baefc840 sleepq_timeout
9 -1/-256 bacea8a0 sleepq_timeout
-2247 -1/-256 baceb920 sleepq_timeout
-2245 -1/-256 baefc2c0 sleepq_timeout
-2232 -1/-256 0 tcp_slowtimo
-2226 -1/-256 0 pfslowtimo
-2203 -1/-256 805718c0 sleepq_timeout
-812 -1/-256 bacb1100 sleepq_timeout
53 0/197 80fbfef0 realtimerexpire
27476 1/275 ba6babc0 sleepq_timeout
30676 1/288 80fbfe40 realtimerexpire
30776 1/288 80fbfd90 realtimerexpire
868 1/427 0 vmem_rehash_all_kick
3376 1/437 b7a65180 sleepq_timeout
7375 1/453 ba039c60 sleepq_timeout
21185 1/507 0 arptimer
122436 2/514 ba6bb400 sleepq_timeout
316869 2/517 0 nd6_slowtimo
597375 2/521 80fbfce0 realtimerexpire
717716 2/523 ba7098c0 tcp_timer_keep
717728 2/523 ba709290 tcp_timer_keep
4317717 2/578 b7a65700 sleepq_timeout
8559269 2/643 0 in6_tmpaddrtimer
8604597 2/643 ba7af458 nd6_llinfo_timer
db{0}> bt/a baceb0e0
trace: pid 0 lid 39 at 0xbacddd74
0xbacddd74: netbsd:mi_switch+0x10
0xbacddda4: netbsd:sleepq_block+0xb4
0xbacddddc: netbsd:cv_wait+0x130
0xbacdde0c: netbsd:usbd_transfer+0x23c
0xbacdde5c: netbsd:usbd_do_request_flags_pipe+0xd8
0xbacdde84: netbsd:usbd_do_request+0x38
0xbacddeb4: netbsd:smsc_read_reg+0x60
0xbacddedc: netbsd:smsc_wait_for_bits+0x4c
0xbacddf04: netbsd:smsc_miibus_readreg+0x4c
0xbacddf2c: netbsd:mii_phy_tick+0x68
0xbacddf4c: netbsd:ukphy_service+0xac
0xbacddf64: netbsd:mii_tick+0x54
0xbacddf7c: netbsd:smsc_tick_task+0x34
0xbacddfac: netbsd:usb_task_thread+0x10c
db{0}> x/i 802c1a3c
netbsd:sosetopt+0x34: ldr r3, [r8]
db{0}> x/i 802c1a8c
netbsd:sosetopt+0x84: mov r0, r9
db{0}>=20
State-Changed-From-To: open->analyzed
State-Changed-By: skrll@NetBSD.org
State-Changed-When: Mon, 07 Dec 2015 07:47:26 +0000
State-Changed-Why:
Problem is understood and being discussed on tech-{kern,net}
http://mail-index.netbsd.org/tech-kern/2015/12/06/msg019747.html
http://mail-index.netbsd.org/tech-net/2015/12/06/msg005443.html
From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Mon, 7 Dec 2015 21:37:11 +0000
This is a multi-part message in MIME format.
--------------080106030607000106010407
Content-Type: text/plain; charset=windows-1252; format=flowed
Content-Transfer-Encoding: 7bit
hi,
Can you try this patch without the assert_sleepable patch and see if it
helps?
thanks,
Nick
--------------080106030607000106010407
Content-Type: text/x-patch;
name="usb.c.diff"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
filename="usb.c.diff"
Index: sys/dev/usb/usb.c
===================================================================
RCS file: /cvsroot/src/sys/dev/usb/usb.c,v
retrieving revision 1.154
diff -u -p -r1.154 usb.c
--- sys/dev/usb/usb.c 25 Jul 2014 08:10:39 -0000 1.154
+++ sys/dev/usb/usb.c 7 Dec 2015 21:35:06 -0000
@@ -212,7 +212,7 @@ usb_attach(device_t parent, device_t sel
aprint_normal("\n");
/* XXX we should have our own level */
- sc->sc_bus->soft = softint_establish(SOFTINT_NET | SOFTINT_MPSAFE,
+ sc->sc_bus->soft = softint_establish(SOFTINT_SERIAL | SOFTINT_MPSAFE,
usb_soft_intr, sc->sc_bus);
if (sc->sc_bus->soft == NULL) {
aprint_error("%s: can't register softintr\n",
--------------080106030607000106010407--
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Mon, 7 Dec 2015 20:28:07 -0800
On Dec 7, 2015, at 1:55 PM, Nick Hudson wrote:
> Can you try this patch without the assert_sleepable patch and see if =
it=20
> helps?
It'd definitely an improvement. No lockup so far.
I'm going to try it using a kernel without LOCKDEBUG, because that =
seemed to make the lockup somewhat harder to provoke.
Thanks,
- Michael
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Tue, 8 Dec 2015 19:27:02 -0800
On Dec 7, 2015, at 9:50 PM, Michael Plass wrote:
> I'm going to try it using a kernel without LOCKDEBUG
It looks good! No more unkillable lockups.
Maybe related, maybe not:
I did have a dropped tcp connection (ip4, I think). Also, I had a ipv6 =
connection
transferring from the pi to my laptop (inetd/chargen on the pi), and =
that transfer stalled - no data moving, but the connection didn't drop. =
This happened twice. The first time I killed the transfer, the other =
one is still in the stuck state.
The kernel and user stack traces are:
db{0}> bt/a b5ce74a0
trace: pid 4567 lid 1 at 0xb4e2fcdc
0xb4e2fcdc: netbsd:mi_switch+0x10
0xb4e2fd0c: netbsd:sleepq_block+0xb4
0xb4e2fd44: netbsd:cv_timedwait_sig+0x108
0xb4e2fee4: netbsd:kevent1+0x2cc
0xb4e2ff0c: netbsd:sys___kevent50+0x38
0xb4e2ff7c: netbsd:syscall+0x88
0xb4e2ffac: netbsd:swi_handler+0x98
db{0}> cont
mipi# gdb /usr/sbin/inetd 21203
GNU gdb (GDB) 7.7.1
Copyright (C) 2014 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later =
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law. Type "show =
copying"
and "show warranty" for details.
This GDB was configured as "arm--netbsdelf-eabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/inetd...(no debugging symbols =
found)...done.
Attaching to program: /usr/sbin/inetd, process 21203
Reading symbols from /usr/lib/libwrap.so.1...(no debugging symbols =
found)...done.
Loaded symbols for /usr/lib/libwrap.so.1
Reading symbols from /usr/lib/libutil.so.7...(no debugging symbols =
found)...done.
Loaded symbols for /usr/lib/libutil.so.7
Reading symbols from /usr/lib/libipsec.so.3...(no debugging symbols =
found)...done.
Loaded symbols for /usr/lib/libipsec.so.3
Reading symbols from /usr/lib/libc.so.12...(no debugging symbols =
found)...done.
Loaded symbols for /usr/lib/libc.so.12
Reading symbols from /usr/libexec/ld.elf_so...(no debugging symbols =
found)...done.
Loaded symbols for /usr/libexec/ld.elf_so
0x401e3358 in write () from /usr/lib/libc.so.12
(gdb) where
#0 0x401e3358 in write () from /usr/lib/libc.so.12
#1 0x00012498 in chargen_stream ()
#2 0x00011b80 in run_service ()
#3 0x00014ffc in main ()
(gdb) quit
Thanks,
- Michael=
From: Nick Hudson <skrll@netbsd.org>
To: gnats-bugs@NetBSD.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
mfpnb@plass-family.net
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0
on raspberry pi 2
Date: Fri, 11 Dec 2015 09:05:35 +0000
On 12/09/15 03:30, Michael Plass wrote:
> The following reply was made to PR kern/50491; it has been noted by GNATS.
>
> From: Michael Plass <mfpnb@plass-family.net>
> To: gnats-bugs@NetBSD.org
> Cc:
> Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
> Date: Tue, 8 Dec 2015 19:27:02 -0800
>
> On Dec 7, 2015, at 9:50 PM, Michael Plass wrote:
>
> > I'm going to try it using a kernel without LOCKDEBUG
>
> It looks good! No more unkillable lockups.
Good news.
>
> Maybe related, maybe not:
> I did have a dropped tcp connection (ip4, I think). Also, I had a ipv6 =
> connection
> transferring from the pi to my laptop (inetd/chargen on the pi), and =
> that transfer stalled - no data moving, but the connection didn't drop. =
> This happened twice. The first time I killed the transfer, the other =
> one is still in the stuck state.
>
> The kernel and user stack traces are:
> db{0}> bt/a b5ce74a0
> trace: pid 4567 lid 1 at 0xb4e2fcdc
> 0xb4e2fcdc: netbsd:mi_switch+0x10
> 0xb4e2fd0c: netbsd:sleepq_block+0xb4
> 0xb4e2fd44: netbsd:cv_timedwait_sig+0x108
> 0xb4e2fee4: netbsd:kevent1+0x2cc
> 0xb4e2ff0c: netbsd:sys___kevent50+0x38
> 0xb4e2ff7c: netbsd:syscall+0x88
> 0xb4e2ffac: netbsd:swi_handler+0x98
> db{0}> cont
Would need some more information about other lwps, I think.
Thanks,
Nick
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Sun, 13 Dec 2015 20:44:26 -0800
I will try to reproduce the stuck tcp transfer again.
I had a v6 connection going for days; it didn't fail until I began the
doing the mdnsd restarts again. But I did not catch it in a stuck state; =
perhaps
the connection timed out.
Thanks,
- Michael
From: Michael Plass <michael@plass-family.net>
To: Nick Hudson <skrll@netbsd.org>
Cc: gnats-bugs@NetBSD.org,
Michael Plass <mfpnb@plass-family.net>
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Mon, 1 Feb 2016 22:39:51 -0800
Nick,
I've been running for 5 days with a NetBSD 7.0 (RPI2) kernel with just
one patch - the one from http://www.netbsd.org/~skrll/usb.softint.diff
I've seen no problems with it - it looks good.
Thanks,
- Michael
From: Michael Plass <mfpnb@plass-family.net>
To: Nick Hudson <skrll@netbsd.org>
Cc: gnats-bugs@NetBSD.org
Subject: Re: kern/50491: unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2
Date: Tue, 17 May 2016 20:07:50 -0700
Nick,
I retested on netbsd-current, just in case the usb stack changes somehow
addressed this problem. But it still happens.
Are you willing to apply http://www.netbsd.org/~skrll/usb.softint.diff to
current at this point? I can test.
Thanks,
- Michael
State-Changed-From-To: analyzed->feedback
State-Changed-By: skrll@NetBSD.org
State-Changed-When: Tue, 01 Nov 2016 16:46:44 +0000
State-Changed-Why:
Fixed in HEAD. ok to close?
From: Michael Plass <mfpnb@plass-family.net>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/50491 (unkillable wait in usbd_transfer while using usmsc0 on raspberry pi 2)
Date: Tue, 1 Nov 2016 20:56:42 -0700
Yes, this can be closed now. Thanks!
- Michael
State-Changed-From-To: feedback->closed
State-Changed-By: wiz@NetBSD.org
State-Changed-When: Wed, 02 Nov 2016 08:23:37 +0000
State-Changed-Why:
Confirmed fixed, thanks!
>Unformatted:
(Contact us)
$NetBSD: query-full-pr,v 1.39 2013/11/01 18:47:49 spz Exp $
$NetBSD: gnats_config.sh,v 1.8 2006/05/07 09:23:38 tsutsui Exp $
Copyright © 1994-2014
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.
Home