https://osmocom.org/https://osmocom.org/favicon.ico?16647414092022-03-14T08:26:38ZOpen Source Mobile CommunicationsE1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=237862022-03-14T08:26:38Ztnt
<ul></ul><p>Well it's definitely "legal" if the device actually responded with a frame shorter.<br />But that shouldn't happen with the icE1usb.</p>
<p>And if the frame was somehow "cut short" on the wire, the CRC would be invalid and the frame rejected.</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=237872022-03-14T10:05:55Zlaforge
<ul></ul><p>There's now a <a href="https://osmocom.org/projects/e1-t1-adapter/repository/osmo-e1d?utf8=%E2%9C%93&rev=laforge%2Fe1oip-trunc" class="external"><code>laforge/e1oip-trunc</code> branch which should fill the missing bytes with random garbage instead of asserting</a> - untested as the problem doesn't appear locally here.</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=237882022-03-15T10:01:25Ztnt
<ul></ul><p>btw <a class="user active" href="https://osmocom.org/users/739890">gruetzkopf</a> if you have any way to make low level bus captures of the event, that would be useful. (openvizsla, logic analyzer, scope, ...)</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=237892022-03-15T16:42:51Zgruetzkopf
<ul></ul><p><a class="user active" href="https://osmocom.org/users/12">tnt</a> I will borrow a fast-enough LA (sadly no openvizla nor LUNA present)</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=248992022-09-15T09:50:45Zlaforge
<ul><li><strong>File</strong> <a href="/attachments/5389">usbmon.pcap</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/5389/usbmon.pcap">usbmon.pcap</a> added</li><li><strong>File</strong> <a href="/attachments/5390">usbmon2.pcap</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/5390/usbmon2.pcap">usbmon2.pcap</a> added</li></ul><p>I've now observed this behavior on the icE1usb + APU3 setup that is supposed to become the co-located OCTOI hub next week.</p>
<p>converting the ASSERT to a LOG statement renders:</p>
<pre>
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=140 size%32=12
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=144 size%32=16
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
<0001> mux_demux.c:423 (I0:L0) IN ASSERT: size=148 size%32=20
</pre>
<p>A usbmon pcap file can be found attached as <a class="attachment" href="https://osmocom.org/attachments/5389">usbmon.pcap</a></p>
<p>As <a class="user active" href="https://osmocom.org/users/12">tnt</a> pointed out, the third iso packet of the URB was alwsy the affected one.</p>
<p>After modifying osmo-e1d to only sumbmit USBs with two iso packets, the problem persisted (now it was the second iso packet in some of the URB which was short). Pcap file of that attempt at <a class="attachment" href="https://osmocom.org/attachments/5390">usbmon2.pcap</a></p>
<p>The USB device in question in those traces is 1.3.2, the ISO IN endpoint is 0x82.</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=249002022-09-15T12:10:48Zlaforge
<ul><li><strong>File</strong> <a href="/attachments/5391">ice1usb-os5490-openvizsla.pcap.bz2</a> <a class="icon-only icon-download" title="Download" href="/attachments/download/5391/ice1usb-os5490-openvizsla.pcap.bz2">ice1usb-os5490-openvizsla.pcap.bz2</a> added</li></ul><p>Attaching an OpenVizsla USB packet trace: <a class="attachment" href="https://osmocom.org/attachments/5391">ice1usb-os5490-openvizsla.pcap.bz2</a></p>
<p>USB address of icE1usb is 22, so <code>usbll.device_addr 22 || usbll.src "22.2"</code> should be the proper filter string</p> E1/T1 Hardware Interface (including icE1usb) - Bug #5490: ISO IN urb sometimes completes with less than full data / incomplete framehttps://osmocom.org/issues/5490?journal_id=249012022-09-15T12:34:06Zlaforge
<ul></ul><pre>
14:14 <@tnt> I'm not seeing any bad packet sizes there.
14:14 -!- wimpman is now known as W|MPy
14:16 <@LaF0rge> tnt: indeed. only three zero-length pckets matching "(usbll.src == "22.2") && !(frame.len == 263)"
14:17 <@LaF0rge> meanwhile at least 40 odd-length packets reported by libusb :(
14:18 <@LaF0rge> [every second]
</pre>
<p>I now had to power-cycle the USB device + rmmod/insmod ehci_pci and of course it works again</p>