USB-to-UART converter dropping data

[iurly]

Original post here: https://www.raspberrypi.org/forums/viewtopic.php?f=28&t=192987
TL;DR:

• I'm seeing sporadic data loss from a Full-Speed USB-to-UART bridge from Silabs (CP2104x) running at 2.000.000 bps (actual data traffic around 1.200.000bps)
• Current settings (tweaking them does not make any difference though):
  dwc_otg.nak_holdoff=2 dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0x7 dwc_otg.speed=1
• First drops occur after about 10-30 minutes
• Identified as a regression between 4.4 and 4.9
• Tested as working with:
  • 4.4.38, 4.4.50 (from pre-compiled release)
  • 4.8.16 (from source commit 061dccc)
• Tested as broken with:
  • 4.9.11 (from source commit ef6bc39)
  • 4.9.37 (from pre-compiled release)
  • 4.9.48 (from pre-compiled release)
  • 4.12.11 (from source commit 8f82f55)
  • 4.13.1 (from source commit 93058c5)

I'm willing to investigate this further and provide any required input, but I can't really bisect the whole tree.
Please give me some guidance as to where to look and how I could reproduce the issue quicker.
Thank you!

[iurly]

@P33M Any idea? Please...

[P33M]

Something falling over after 10 minutes would seem to be a reproducible test.

Without the device at the other end of the UART I won't be able to replicate it, however.

Is there any way of using a PC to emulate the device? You say you send 1.2mbit/s of data across a 2Mbaud link - can you create an equivalent mini test program that feeds the correct amount of data into the UART?

[iurly]

Yes, I could do that, though you'd probably need a couple of those CP2104 converters.
Any chance you already have those? Or perhaps I can try to reproduce this issue in some other way?

[P33M]

CP2104 is commodity hardware, I'm sure it won't be too hard to find a converter that has one embedded.

[iurly]

I create a test program:
https://gist.github.com/iurly/64a98566384f6f3fbd59d57f475db702
The hardware setup involves two cross-connected CP2104's.
I'm using a PC at the sender's side and a Raspberry Pi at the receiver's side:

• On a 4.9.11 I was able to reproduce the issue within a few minutes
• On a 4.4.50 it's been running without any issue for about a half hour and I'm going to leave it running the whole day.
  Please let me know if you can get a hold of such devices.
  Thank you!

[iurly]

Since it's definitely a regression and I could automate the whole testing process, it should not be that hard to find the offending commit.
If you could help me understand how the rpi kernel evolves (compared to the vanilla kernel) I could probably find it myself.
Thank you!

[thomasrudin]

I have the same issue, but with a pl2303 (gps dongle) and an Arduino (cdc_acm) but it only occurs if the pl2303 is talking, otherwise everything works fine...

[thomasrudin]

Additionally: if i set dwc_otg.speed=1 the problem goes away too

[iurly]

@thomasrudin did you try with a previous kernel version, before 4.9?
Btw, I was also using a pl2303 at the beginning and then moved to CP2104 because it seemed much more reliable. IIRC the pl2303 did not even work reliably on a PC at 921.600 bps.

[thomasrudin]

i have my test setup ready, which branch/commit should i test?

[iurly]

See the original post

[thomasrudin]

Bad news, i think i have another problem:

4.9.50-v7 bad
4.8.16-v7 bad (commit: 061dccce6cf6705bbb5da29a643f4b0ad1d11630)

[iurly]

Do you have the following settings in your /boot/cmdline.txt?
dwc_otg.nak_holdoff=2 dwc_otg.fiq_enable=1 dwc_otg.fiq_fsm_enable=1 dwc_otg.fiq_fsm_mask=0x7

[thomasrudin]

tested the settings in cmdline.txt but i have the same problem as before, maybe pl2303 related.

[thomasrudin]

I solved my problems with the workaround described in #2140:
dwc_otg.fiq_fsm_mask=0x2

I have now a stable communication with the cdc and pl2303 drivers (@115.2kbaud) in kernel 4.9.50-v7
Sorry for not contributing to this issue...

[P33M]

Bisecting on this repository is a bit cumbersome but knowing how the branches work may help -

When a new kernel is released, we create a new branch and start work to find out what's been broken/what kernel API changes have been made/what drivers have been renamed/removed/added. In this development phase, branches are rebased frequently until they are usable enough to be pushed out via rpi-update. At this point, we stop rebasing and start pulling in upstream fixes and merging them. Once the "stable" branch is moved to a new release, the old branch is no longer updated - this can take several months.

This leads to deep branches with a reasonably high probability that the breaking commit is not in the branch commits.

If you have something that's broken in the latest release of e.g. rpi-4.9.y, then you can perform a semi-manual bisect by testing the latest commit on the branch, then testing the earliest commit on the branch (usually the tag by Linus that denotes the first version of the kernel release). If both are bad, then start the bisect at the first commit in the branch. This then gets you testing the commits that happened during the upstream merge window.

Unfortunately this means that you then have a potentially broken kernel (as no downstream patched applied) which means manually patching with the first few commits that turn an upstream kernel into a downstream one. The patches that get an upstream kernel working are usually the first few made by either popcornmix or pelwell on the relevant branch.

It may be easier to bisect by having two copies of the repository - one that you mangle slightly with downstream patches and an unedited one so git stays happy.

[iurly]

Thanks for your reply, it really helps a lot to get a feel of how the whole process works.

First, let me state that the offending commit is either one of the patches from 4.9 to 4.9.11 (very unlikely) or took place during the merge window for 4.9 (very likely).

Unfortunately, I'm not quite sure I understand what you mean by "first commit in the branch".
A far as I know, there's no trivial way of telling when/where a branch was first made, short of looking at the graphs produced by gitk. In my understanding, you guys kept rebasing rpi-4.9.y, by applying downstream patches, until 4.9.11. So this would be an exception to your statement "(usually the tag by Linus that denotes the first version of the kernel release)", right? The first commit in the branch is therefore:

5e311ac415aada96231334af805fb27e52610645
smsx95xx: fix crimes against truesize

The last one being:

ef6bc39100c98f12ded8011abe979e392e161c0c
dmaengine: bcm2835: Fix cyclic DMA period splitting

Leaving me with 186 patches to apply on top of an upstream kernel for each test.
I guess I could first bisect this branch to get a feeling of how many of those are really needed for my tests
(i.e. "the first few commits that turn an upstream kernel into a downstream one") and what not. Unless you'd be so kind to filter them out for me. :-)

Then I would try applying the downstream patches to 4.9 (just to make sure it's not any of the backports).
If this also turns out to be bad (which it likely will), I could bisect between 4.8 and 4.9, right? Perhaps by moving manually between 4.9-rc1 and 4.9-rc8 first.

Is my understanding correct?
Thanks!

[chrisspen]

I'm also experiencing a similar problem communicating between a RPi3 and an Arduino Uno over a USB serrial connection. This might be related to a bug reported in the firmware project.

[JamesH65]

@iurly Did you or anyone else have any luck finding the commit that caused this issue?

It might be worth trying the latest 4.14 kernel, just to see if that works.

[iurly]

No, I never managed to find it. So far I'v been circumventing the problem by sticking to a 4.8.
I'll give the 4.14 a shot in the next few days.

[iurly]

I tested the following:

Linux rpi3-can1 4.14.52-v7+ #1123 SMP Wed Jun 27 17:35:49 BST 2018 armv7l GNU/Linux

and it works!
I can reproduce the issue relatively quickly, I'm willing to try different binary kernels if anyone could provide some procedure to bisect over them, so we can at least identify a range of broken release.

[pelwell]

Thanks for the feedback. You can download intermediate kernel builds using rpi-update (all releases are listed here), but if the current kernel builds work then there we are unlikely to want to cherry-pick the fixing patch - the recommended solution will be to upgrade.

[iurly]

Even with a known-to-work kernel, I'm still experiencing occasional data loss.
I reckon it might have to do with the priority of the kernel threads involved:
kworker/u8:2, kworker/u8:3. I would change their scheduling policy to e.g. RT_FIFO, but they keep getting killed and recreated once an hour or so (which is the frequency at which I experience the data loss).
Any thoughts?

[JamesH65]

Can anyone still seeing a problem make sure they are running the latest kernel. There have been a lot of changes in the last year that might help with this.

This issue will be closed within 30 days unless further interactions are posted. If you wish this issue to remain open, please add a comment. A closed issue may be reopened if requested.

[JamesH65]

Closing due to lack of activity. Please request to be reopened if you feel this issue is still relevant.