Re: kern/50278: umidi(4) loses first incoming message after second open

To: kern-bug-people%netbsd.org@localhost,gnats-admin%netbsd.org@localhost,netbsd-bugs%netbsd.org@localhost,gson%gson.org@localhost (Andreas Gustafsson)
Subject: Re: kern/50278: umidi(4) loses first incoming message after second open
From: Andreas Gustafsson <gson%gson.org@localhost>
Date: Wed, 27 Nov 2019 17:05:01 +0000 (UTC)
The following reply was made to PR kern/50278; it has been noted by GNATS.

From: Andreas Gustafsson <gson%gson.org@localhost>
To: Nick Hudson <nick.hudson%gmx.co.uk@localhost>
Cc: gnats-bugs%netbsd.org@localhost
Subject: Re: kern/50278: umidi(4) loses first incoming message after second open
Date: Wed, 27 Nov 2019 19:00:39 +0200

 Nick Hudson wrote:
 > what does your usb protocol analyser say?
 
 I have now analyzed the USB traffic using an OHCI, with my patch from
 PR 54070, and with midi.c patched to disable the sending of "MIDI
 active sense" to avoid cluttering the logs with unrelated traffic.
 
 When I run the test program for the first time, the analyzer shows a
 single 4-byte OUT transaction containing a single DATA0 packet,
 followed by a single 4-byte IN transaction containing a single DATA0
 packet.
 
 When I run the test program for the second time, the analyzer shows a
 single 4-byte OUT transaction containing a single DATA1 packet,
 followed by a single 4-byte IN transaction containing a single DATA1
 packet.
 
 All the transfers contain the same data, 09 90 40 7F.  In other words,
 everything looks as expected on the wire.  But in the UMIDI_DEBUG
 output, the first run of the test program receives input:
 
 [   241.023669] umidi_open: sc=0xfffff464bd776320
 [   241.023669] umidi out: 45.089117s ep=0xfffff464bd7c94c8 cn=0 len=3 cin=0x9
 [   241.023669] umidi0: umidi packet(out): 09 90 40 7F
 [   241.023669] umidi out transfer: start 0xffff990051ff0a80 end 0xffff990051ff0a84 length 4
 [   241.023669] umidi0: 45.091502s out ep 0xfffff464bd7c94c8 xfer length 4
 [   241.023669] umidi0: input endpoint 0xfffff464bd7c95a8 transfer length 4
 [   241.023669] umidi0: input endpoint 0xfffff464bd7c95a8 cable 0 len 3: 90 40 7F
 
 and the second one does not:
 
 [   246.176453] umidi_open: sc=0xfffff464bd776320
 [   246.176453] umidi out: 50.248899s ep=0xfffff464bd7c94c8 cn=0 len=3 cin=0x9
 [   246.176453] umidi0: umidi packet(out): 09 90 40 7F
 [   246.176453] umidi out transfer: start 0xffff990051ff0a80 end 0xffff990051ff0a84 length 4
 [   246.186539] umidi0: 50.251081s out ep 0xfffff464bd7c94c8 xfer length 4
 
 The OHCIDEBUG output looks like this (with comments in parenthesis to
 correlate the timeline to the test program runs):
 
 (start test program for the first time)
 
 1574871545.089078 ohci_device_bulk_start#6@0: called!
 1574871545.089079 ohci_device_bulk_start#6@0: xfer=0xfffff4645591d578 len=64 isread=1 flags=4
 1574871545.089079 ohci_device_bulk_start#6@0: endpt=129
 1574871545.089081 ohci_reset_std_chain#44@0: called!
 1574871545.089082 ohci_reset_std_chain#44@0: start len=64
 1574871545.089082 ohci_reset_std_chain#44@0: addr=3 endpt=1 len=64 speed=2
 1574871545.089083 ohci_reset_std_chain#44@0: sdataphys=0x45963a40 edataphys=0x45963a7f len=64 curlen=64
 1574871545.089085 ohci_device_bulk_start#6@0: xfer 0xfffff4645591d578 data 0xffff99005294fd00 tail 0xffff99005294fe20
 1574871545.089085 ohci_device_bulk_start#6@0: ed_flags=0x00400083 td_flags=0xfffffffff0340000 td_cbp=0x45963a40 td_be=0x45963a7f
 1574871545.089086 ohci_device_bulk_start#6@0: --- dump start ---
 1574871545.089086 ohci_dump_ed#59@0: called!
 1574871545.089087 ohci_dump_ed#59@0: ED(0xffff990051275e40) at 0x452a5e40:
 1574871545.089088 ohci_dump_ed#59@0:     addr=3 endpt=1 maxp=64
 1574871545.089088 ohci_dump_ed#59@0:     dir=0 speed=0 skip=0 iso=0
 1574871545.089089 ohci_dump_ed#59@0:     tailp=0x45bdbd00
 1574871545.089089 ohci_dump_ed#59@0:     headp=0x45bdbd00 nexted=0x452a5e80 halted=0 carry=0
 1574871545.089090 ohci_dump_td#312@0: called!
 1574871545.089090 ohci_dump_td#312@0: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871545.089091 ohci_dump_td#312@0:     round=1 DP=2 DI=1 T=0
 1574871545.089091 ohci_dump_td#312@0:     EC=0 CC=15
 1574871545.089092 ohci_dump_td#312@0:     td_cbp=0x45963a40 td_nexttd=0x45bdbe20 td_be=0x45963a7f
 1574871545.089092 ohci_dump_td#313@0: called!
 1574871545.089093 ohci_dump_td#313@0: TD(0xffff99005294fe20) at 0x45bdbe20:
 1574871545.089094 ohci_dump_td#313@0:     round=0 DP=0 DI=0 T=0
 1574871545.089094 ohci_dump_td#313@0:     EC=0 CC=0
 1574871545.089095 ohci_dump_td#313@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871545.089095 ohci_device_bulk_start#6@0: --- dump end ---
 1574871545.089478 ohci_device_bulk_start#7@0: called!
 1574871545.089478 ohci_device_bulk_start#7@0: xfer=0xfffff4645591d428 len=4 isread=0 flags=0
 1574871545.089479 ohci_device_bulk_start#7@0: endpt=1
 1574871545.089480 ohci_reset_std_chain#45@0: called!
 1574871545.089480 ohci_reset_std_chain#45@0: start len=4
 1574871545.089481 ohci_reset_std_chain#45@0: addr=3 endpt=1 len=4 speed=2
 1574871545.089482 ohci_reset_std_chain#45@0: sdataphys=0x45963a80 edataphys=0x45963a83 len=4 curlen=4
 1574871545.089483 ohci_device_bulk_start#7@0: xfer 0xfffff4645591d428 data 0xffff99005294ff40 tail 0xffff99005294fd60
 1574871545.089483 ohci_device_bulk_start#7@0: ed_flags=0x00400083 td_flags=0xfffffffff0280000 td_cbp=0x45963a80 td_be=0x45963a83
 1574871545.089484 ohci_device_bulk_start#7@0: --- dump start ---
 1574871545.089484 ohci_dump_ed#60@0: called!
 1574871545.089485 ohci_dump_ed#60@0: ED(0xffff990051275e80) at 0x452a5e80:
 1574871545.089485 ohci_dump_ed#60@0:     addr=3 endpt=1 maxp=64
 1574871545.089486 ohci_dump_ed#60@0:     dir=0 speed=0 skip=0 iso=0
 1574871545.089486 ohci_dump_ed#60@0:     tailp=0x45bdbf40
 1574871545.089487 ohci_dump_ed#60@0:     headp=0x45bdbf40 nexted=0x00000000 halted=0 carry=0
 1574871545.089488 ohci_dump_td#314@0: called!
 1574871545.089488 ohci_dump_td#314@0: TD(0xffff99005294ff40) at 0x45bdbf40:
 1574871545.089489 ohci_dump_td#314@0:     round=0 DP=1 DI=1 T=0
 1574871545.089489 ohci_dump_td#314@0:     EC=0 CC=15
 1574871545.089490 ohci_dump_td#314@0:     td_cbp=0x45963a80 td_nexttd=0x45bdbd60 td_be=0x45963a83
 1574871545.089490 ohci_dump_td#315@0: called!
 1574871545.089491 ohci_dump_td#315@0: TD(0xffff99005294fd60) at 0x45bdbd60:
 1574871545.089491 ohci_dump_td#315@0:     round=0 DP=0 DI=0 T=0
 1574871545.089492 ohci_dump_td#315@0:     EC=0 CC=0
 1574871545.089492 ohci_dump_td#315@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871545.089493 ohci_device_bulk_start#7@0: --- dump end ---
 1574871545.091468 ohci_intr#60@0: called!
 1574871545.091470 ohci_intr1#60@0: called!
 1574871545.091472 ohci_intr1#60@0: sc=0xffff990005177000
 1574871545.091473 ohci_intr1#60@0: intrs=0x26(0x2) eintrs=0x2(0x5b)
 1574871545.091475 ohci_intr1#60@0: sc 0xffff990005177000 blocking intrs 0x2
 1574871545.091484 ohci_softintr#53@0: called!
 1574871545.091485 ohci_softintr#53@0: add TD 0xffff99005294fd00
 1574871545.091486 ohci_softintr#53@0: add TD 0xffff99005294ff40
 1574871545.091487 ohci_softintr#53@0: sdone=0xffff99005294ff40 sidone=0
 1574871545.091487 ohci_softintr#53@0: --- TD dump start ---
 1574871545.091488 ohci_dump_td#316@0: called!
 1574871545.091488 ohci_dump_td#316@0: TD(0xffff99005294ff40) at 0x45bdbf40:
 1574871545.091489 ohci_dump_td#316@0:     round=0 DP=1 DI=1 T=3
 1574871545.091489 ohci_dump_td#316@0:     EC=0 CC=0
 1574871545.091490 ohci_dump_td#316@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x45963a83
 1574871545.091491 ohci_dump_td#317@0: called!
 1574871545.091491 ohci_dump_td#317@0: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871545.091492 ohci_dump_td#317@0:     round=1 DP=2 DI=1 T=3
 1574871545.091492 ohci_dump_td#317@0:     EC=0 CC=0
 1574871545.091493 ohci_dump_td#317@0:     td_cbp=0x45963a44 td_nexttd=0x45bdbf40 td_be=0x45963a7f
 1574871545.091493 ohci_softintr#53@0: --- TD dump end ---
 1574871545.091494 ohci_softintr#53@0: std=0xffff99005294ff40 xfer=0xfffff4645591d428 hcpriv=0xffff99005294ff40
 1574871545.091497 ohci_softintr#53@0: len=4, flags=0x3
 1574871545.091499 ohci_device_bulk_done#6@0: called!
 1574871545.091499 ohci_device_bulk_done#6@0: xfer=0xfffff4645591d428, actlen=4
 1574871545.091673 ohci_softintr#53@0: std=0xffff99005294fd00 xfer=0xfffff4645591d578 hcpriv=0xffff99005294fd00
 1574871545.091675 ohci_softintr#53@0: len=4, flags=0x3
 1574871545.091676 ohci_device_bulk_done#7@0: called!
 1574871545.091677 ohci_device_bulk_done#7@0: xfer=0xfffff4645591d578, actlen=4
 1574871545.091948 ohci_device_bulk_start#8@0: called!
 1574871545.091948 ohci_device_bulk_start#8@0: xfer=0xfffff4645591d578 len=64 isread=1 flags=4
 1574871545.091949 ohci_device_bulk_start#8@0: endpt=129
 1574871545.091950 ohci_reset_std_chain#46@0: called!
 1574871545.091950 ohci_reset_std_chain#46@0: start len=64
 1574871545.091951 ohci_reset_std_chain#46@0: addr=3 endpt=1 len=64 speed=2
 1574871545.091951 ohci_reset_std_chain#46@0: sdataphys=0x45963a40 edataphys=0x45963a7f len=64 curlen=64
 1574871545.091952 ohci_device_bulk_start#8@0: xfer 0xfffff4645591d578 data 0xffff99005294fe20 tail 0xffff99005294fd00
 1574871545.091953 ohci_device_bulk_start#8@0: ed_flags=0x00400083 td_flags=0xfffffffff0340000 td_cbp=0x45963a40 td_be=0x45963a7f
 1574871545.091953 ohci_device_bulk_start#8@0: --- dump start ---
 1574871545.091954 ohci_dump_ed#61@0: called!
 1574871545.091954 ohci_dump_ed#61@0: ED(0xffff990051275e40) at 0x452a5e40:
 1574871545.091955 ohci_dump_ed#61@0:     addr=3 endpt=1 maxp=64
 1574871545.091955 ohci_dump_ed#61@0:     dir=0 speed=0 skip=0 iso=0
 1574871545.091956 ohci_dump_ed#61@0:     tailp=0x45bdbe20
 1574871545.091956 ohci_dump_ed#61@0:     headp=0x45bdbe22 nexted=0x452a5e80 halted=0 carry=1
 1574871545.091957 ohci_dump_td#318@0: called!
 1574871545.091957 ohci_dump_td#318@0: TD(0xffff99005294fe20) at 0x45bdbe20:
 1574871545.091958 ohci_dump_td#318@0:     round=1 DP=2 DI=1 T=0
 1574871545.091958 ohci_dump_td#318@0:     EC=0 CC=15
 1574871545.091959 ohci_dump_td#318@0:     td_cbp=0x45963a40 td_nexttd=0x45bdbd00 td_be=0x45963a7f
 1574871545.091959 ohci_dump_td#319@0: called!
 1574871545.091960 ohci_dump_td#319@0: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871545.091960 ohci_dump_td#319@0:     round=0 DP=0 DI=0 T=0
 1574871545.091961 ohci_dump_td#319@0:     EC=0 CC=0
 1574871545.091961 ohci_dump_td#319@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871545.091962 ohci_device_bulk_start#8@0: --- dump end ---
 1574871545.091964 ohci_softintr#53@0: --- ITD dump start ---
 1574871545.091964 ohci_softintr#53@0: --- ITD dump end ---
 1574871545.091965 ohci_softintr#53@0: done
 1574871545.092365 ohci_device_bulk_abort#3@0: called!
 1574871545.092366 ohci_device_bulk_abort#3@0: xfer=0xfffff4645591d578
 1574871545.092366 ohci_abort_xfer#3@0: called!
 1574871545.092367 ohci_abort_xfer#3@0: xfer=0xfffff4645591d578 pipe=0xfffff464bd34e408 sed=0xffff990051275e40
 1574871545.092371 ohci_abort_xfer#3@0: stop ed=0xffff990051275e40
 1574871545.120100 ohci_abort_xfer#3@0: --- dump start ---
 1574871545.120100 ohci_abort_xfer#3@0: sed:
 1574871545.120101 ohci_dump_ed#62@0: called!
 1574871545.120101 ohci_dump_ed#62@0: ED(0xffff990051275e40) at 0x452a5e40:
 1574871545.120102 ohci_dump_ed#62@0:     addr=3 endpt=1 maxp=64
 1574871545.120102 ohci_dump_ed#62@0:     dir=0 speed=0 skip=1 iso=0
 1574871545.120103 ohci_dump_ed#62@0:     tailp=0x45bdbd00
 1574871545.120103 ohci_dump_ed#62@0:     headp=0x45bdbe22 nexted=0x452a5e80 halted=0 carry=1
 1574871545.120104 ohci_dump_td#320@0: called!
 1574871545.120105 ohci_dump_td#320@0: TD(0xffff99005294fe20) at 0x45bdbe20:
 1574871545.120105 ohci_dump_td#320@0:     round=1 DP=2 DI=1 T=0
 1574871545.120106 ohci_dump_td#320@0:     EC=0 CC=15
 1574871545.120106 ohci_dump_td#320@0:     td_cbp=0x45963a40 td_nexttd=0x45bdbd00 td_be=0x45963a7f
 1574871545.120107 ohci_dump_td#321@0: called!
 1574871545.120107 ohci_dump_td#321@0: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871545.120108 ohci_dump_td#321@0:     round=0 DP=0 DI=0 T=0
 1574871545.120108 ohci_dump_td#321@0:     EC=0 CC=0
 1574871545.120109 ohci_dump_td#321@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871545.120109 ohci_abort_xfer#3@0: --- dump end ---
 1574871545.120110 ohci_abort_xfer#3@0: set hd=0x45bdbd00, tl=0x45bdbd00
 1574871545.120111 ohci_device_bulk_done#8@0: called!
 1574871545.120111 ohci_device_bulk_done#8@0: xfer=0xfffff4645591d578, actlen=0
 
 (test program exits having received a message)
 
 (start test program for the second time)
 
 1574871550.248864 ohci_device_bulk_start#9@1: called!
 1574871550.248865 ohci_device_bulk_start#9@1: xfer=0xfffff4645591d578 len=64 isread=1 flags=4
 1574871550.248865 ohci_device_bulk_start#9@1: endpt=129
 1574871550.248866 ohci_reset_std_chain#47@1: called!
 1574871550.248867 ohci_reset_std_chain#47@1: start len=64
 1574871550.248868 ohci_reset_std_chain#47@1: addr=3 endpt=1 len=64 speed=2
 1574871550.248869 ohci_reset_std_chain#47@1: sdataphys=0x45963a40 edataphys=0x45963a7f len=64 curlen=64
 1574871550.248869 ohci_device_bulk_start#9@1: xfer 0xfffff4645591d578 data 0xffff99005294fd00 tail 0xffff99005294fe20
 1574871550.248870 ohci_device_bulk_start#9@1: ed_flags=0x00400083 td_flags=0xfffffffff0340000 td_cbp=0x45963a40 td_be=0x45963a7f
 1574871550.248871 ohci_device_bulk_start#9@1: --- dump start ---
 1574871550.248871 ohci_dump_ed#63@1: called!
 1574871550.248872 ohci_dump_ed#63@1: ED(0xffff990051275e40) at 0x452a5e40:
 1574871550.248872 ohci_dump_ed#63@1:     addr=3 endpt=1 maxp=64
 1574871550.248873 ohci_dump_ed#63@1:     dir=0 speed=0 skip=0 iso=0
 1574871550.248873 ohci_dump_ed#63@1:     tailp=0x45bdbd00
 1574871550.248874 ohci_dump_ed#63@1:     headp=0x45bdbd00 nexted=0x452a5e80 halted=0 carry=0
 1574871550.248874 ohci_dump_td#322@1: called!
 1574871550.248875 ohci_dump_td#322@1: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871550.248875 ohci_dump_td#322@1:     round=1 DP=2 DI=1 T=0
 1574871550.248876 ohci_dump_td#322@1:     EC=0 CC=15
 1574871550.248876 ohci_dump_td#322@1:     td_cbp=0x45963a40 td_nexttd=0x45bdbe20 td_be=0x45963a7f
 1574871550.248877 ohci_dump_td#323@1: called!
 1574871550.248878 ohci_dump_td#323@1: TD(0xffff99005294fe20) at 0x45bdbe20:
 1574871550.248878 ohci_dump_td#323@1:     round=0 DP=0 DI=0 T=0
 1574871550.248879 ohci_dump_td#323@1:     EC=0 CC=0
 1574871550.248879 ohci_dump_td#323@1:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871550.248880 ohci_device_bulk_start#9@1: --- dump end ---
 1574871550.249262 ohci_device_bulk_start#10@1: called!
 1574871550.249263 ohci_device_bulk_start#10@1: xfer=0xfffff4645591d428 len=4 isread=0 flags=0
 1574871550.249264 ohci_device_bulk_start#10@1: endpt=1
 1574871550.249265 ohci_reset_std_chain#48@1: called!
 1574871550.249265 ohci_reset_std_chain#48@1: start len=4
 1574871550.249266 ohci_reset_std_chain#48@1: addr=3 endpt=1 len=4 speed=2
 1574871550.249267 ohci_reset_std_chain#48@1: sdataphys=0x45963a80 edataphys=0x45963a83 len=4 curlen=4
 1574871550.249267 ohci_device_bulk_start#10@1: xfer 0xfffff4645591d428 data 0xffff99005294fd60 tail 0xffff99005294ff40
 1574871550.249268 ohci_device_bulk_start#10@1: ed_flags=0x00400083 td_flags=0xfffffffff0280000 td_cbp=0x45963a80 td_be=0x45963a83
 1574871550.249268 ohci_device_bulk_start#10@1: --- dump start ---
 1574871550.249269 ohci_dump_ed#64@1: called!
 1574871550.249269 ohci_dump_ed#64@1: ED(0xffff990051275e80) at 0x452a5e80:
 1574871550.249270 ohci_dump_ed#64@1:     addr=3 endpt=1 maxp=64
 1574871550.249271 ohci_dump_ed#64@1:     dir=0 speed=0 skip=0 iso=0
 1574871550.249271 ohci_dump_ed#64@1:     tailp=0x45bdbd60
 1574871550.249272 ohci_dump_ed#64@1:     headp=0x45bdbd62 nexted=0x00000000 halted=0 carry=1
 1574871550.249272 ohci_dump_td#324@1: called!
 1574871550.249273 ohci_dump_td#324@1: TD(0xffff99005294fd60) at 0x45bdbd60:
 1574871550.249273 ohci_dump_td#324@1:     round=0 DP=1 DI=1 T=0
 1574871550.249274 ohci_dump_td#324@1:     EC=0 CC=15
 1574871550.249274 ohci_dump_td#324@1:     td_cbp=0x45963a80 td_nexttd=0x45bdbf40 td_be=0x45963a83
 1574871550.249275 ohci_dump_td#325@1: called!
 1574871550.249275 ohci_dump_td#325@1: TD(0xffff99005294ff40) at 0x45bdbf40:
 1574871550.249276 ohci_dump_td#325@1:     round=0 DP=0 DI=0 T=0
 1574871550.249276 ohci_dump_td#325@1:     EC=0 CC=0
 1574871550.249277 ohci_dump_td#325@1:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871550.249277 ohci_device_bulk_start#10@1: --- dump end ---
 1574871550.251052 ohci_intr#61@0: called!
 1574871550.251054 ohci_intr1#61@0: called!
 1574871550.251055 ohci_intr1#61@0: sc=0xffff990005177000
 1574871550.251056 ohci_intr1#61@0: intrs=0x6(0x2) eintrs=0x2(0x5b)
 1574871550.251058 ohci_intr1#61@0: sc 0xffff990005177000 blocking intrs 0x2
 1574871550.251066 ohci_softintr#54@0: called!
 1574871550.251067 ohci_softintr#54@0: add TD 0xffff99005294fd60
 1574871550.251068 ohci_softintr#54@0: sdone=0xffff99005294fd60 sidone=0
 1574871550.251069 ohci_softintr#54@0: --- TD dump start ---
 1574871550.251069 ohci_dump_td#326@0: called!
 1574871550.251070 ohci_dump_td#326@0: TD(0xffff99005294fd60) at 0x45bdbd60:
 1574871550.251070 ohci_dump_td#326@0:     round=0 DP=1 DI=1 T=2
 1574871550.251071 ohci_dump_td#326@0:     EC=0 CC=0
 1574871550.251072 ohci_dump_td#326@0:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x45963a83
 1574871550.251072 ohci_softintr#54@0: --- TD dump end ---
 1574871550.251073 ohci_softintr#54@0: std=0xffff99005294fd60 xfer=0xfffff4645591d428 hcpriv=0xffff99005294fd60
 1574871550.251076 ohci_softintr#54@0: len=4, flags=0x3
 1574871550.251077 ohci_device_bulk_done#9@0: called!
 1574871550.251077 ohci_device_bulk_done#9@0: xfer=0xfffff4645591d428, actlen=4
 1574871550.251253 ohci_softintr#54@0: --- ITD dump start ---
 1574871550.251254 ohci_softintr#54@0: --- ITD dump end ---
 1574871550.251255 ohci_softintr#54@0: done
 
 (test program is blocking in read() for 5 seconds until it gets a SIGALRM)
 
 1574871555.273755 ohci_device_bulk_abort#4@1: called!
 1574871555.273755 ohci_device_bulk_abort#4@1: xfer=0xfffff4645591d578
 1574871555.273756 ohci_abort_xfer#4@1: called!
 1574871555.273757 ohci_abort_xfer#4@1: xfer=0xfffff4645591d578 pipe=0xfffff464bd34e408 sed=0xffff990051275e40
 1574871555.273762 ohci_abort_xfer#4@1: stop ed=0xffff990051275e40
 1574871555.303822 ohci_abort_xfer#4@1: --- dump start ---
 1574871555.303822 ohci_abort_xfer#4@1: sed:
 1574871555.303823 ohci_dump_ed#65@1: called!
 1574871555.303823 ohci_dump_ed#65@1: ED(0xffff990051275e40) at 0x452a5e40:
 1574871555.303824 ohci_dump_ed#65@1:     addr=3 endpt=1 maxp=64
 1574871555.303825 ohci_dump_ed#65@1:     dir=0 speed=0 skip=1 iso=0
 1574871555.303825 ohci_dump_ed#65@1:     tailp=0x45bdbe20
 1574871555.303826 ohci_dump_ed#65@1:     headp=0x45bdbd00 nexted=0x452a5e80 halted=0 carry=0
 1574871555.303826 ohci_dump_td#327@1: called!
 1574871555.303827 ohci_dump_td#327@1: TD(0xffff99005294fd00) at 0x45bdbd00:
 1574871555.303827 ohci_dump_td#327@1:     round=1 DP=2 DI=1 T=2
 1574871555.303828 ohci_dump_td#327@1:     EC=1 CC=3
 1574871555.303828 ohci_dump_td#327@1:     td_cbp=0x45963a40 td_nexttd=0x45bdbe20 td_be=0x45963a7f
 1574871555.303829 ohci_dump_td#328@1: called!
 1574871555.303830 ohci_dump_td#328@1: TD(0xffff99005294fe20) at 0x45bdbe20:
 1574871555.303830 ohci_dump_td#328@1:     round=0 DP=0 DI=0 T=0
 1574871555.303831 ohci_dump_td#328@1:     EC=0 CC=0
 1574871555.303831 ohci_dump_td#328@1:     td_cbp=0x00000000 td_nexttd=0x00000000 td_be=0x00000000
 1574871555.303832 ohci_abort_xfer#4@1: --- dump end ---
 1574871555.303833 ohci_abort_xfer#4@1: set hd=0x45bdbe20, tl=0x45bdbe20
 1574871555.303834 ohci_device_bulk_done#10@1: called!
 1574871555.303834 ohci_device_bulk_done#10@1: xfer=0xfffff4645591d578, actlen=0
 
 (test program exits)
 
 I suspect the problem is the "carry=0" at 1574871550.248874.
 -- 
 Andreas Gustafsson, gson%gson.org@localhost
Prev by Date: Re: misc/54716 (feedback.cgi doesn't work)
Next by Date: NetBSD Nightly Trouble Ticket Report
Previous by Thread: Re: kern/50278: umidi(4) loses first incoming message after second open
Next by Thread: Re: kern/50278: umidi(4) loses first incoming message after second open
Indexes:
Home | Main Index | Thread Index | Old Index