Strange SerialUSB behaviour on Linux

[JoeEarlam]

Hi there, I'm having some weird trouble with Serial and I wanted to check if; 1. I'm doing anything stupid, and 2. Who to submit the bug report to 😁

If I wait more than two or three seconds between serial prints, the serial terminal doesn't register the new data coming through. If you unplug and re-plug (pico is powered separate from the USB cable) you'll see the next message come through, but nothing again after that. If you send a newline every second as a "Keepalive", the code works as expected, just with lots of stray newlines. On a Windows machine with IDE 1.8.x the code works as expected. The LED in the keepalive routine flashes continuously, so the MCU hasn't crashed.

Any ideas? I have tried multiple cables, ports, and MCUs, and the problem only occurs on my workstation. I've included some relevant info and my test code below.

Thanks!

Code:

void setup() {
  pinMode(LED_BUILTIN, OUTPUT);
  Serial.begin(115200);

  while (!Serial)
    ;
  delay(1000);
}

uint32_t lastSerTime;
uint32_t lastKeepAliveTime;
uint16_t interval = 2000;

void loop() {
  if (millis() > lastSerTime + interval) {
    lastSerTime = millis();
    Serial.print("Interval: ");
    Serial.println(interval);
    interval = interval + 100;
  }

  if (millis() > lastKeepAliveTime + 1000) {
    lastKeepAliveTime = millis();
    digitalWrite(LED_BUILTIN, !digitalRead(LED_BUILTIN));
    //Serial.println();    //serial works when uncommented
  }
}

Received data:

12:14:19.411 -> Interval: 2100
12:14:34.405 -> Interval: 2100
12:14:36.319 -> Interval: 2200
12:14:38.504 -> Interval: 2300
12:14:40.821 -> Interval: 2400
12:14:43.202 -> Interval: 2500
12:14:45.713 -> Interval: 2600
(No more data received, reinsert cable)
12:16:48.944 -> Interval: 3000
(no more data received...)

uname -a:
Linux [HOSTNAME] 5.15.0-71-generic #78~20.04.1-Ubuntu SMP Wed Apr 19 11:26:48 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

[Andy2No]

A bit of a long shot, but it might be best to not assume that implicit type casting is going to do what you expect. E.g. see: https://forum.arduino.cc/t/typecasting-trouble-converting-from-int-to-unsigned-long/184740

millis() returns unsigned long, which fair enough, is equivalent to uin32_t, but you're also relying on the compiler to correctly handle casting a uint16_t to unint32_t, and treating a literal constants as uint32_t, without specifying that it is. It seems like that should do what you'd expect, but maybe it isn't. E.g. you could say 100ul instead of just 1000 to make it clearer.

Personally, I try to stick to all variables involved in calculations / comparisons with millis() or micros() having the same type that is returned - unsigned long.

Comparisons with millis() are normally pretty safe, however you do them, because it takes 50 days (allegedly) to return to zero. Ones with micros() are more of a problem - taking about 70 minutes, IIRC. However, if the compiler were to mess up the casting of types, you may get a different answer all together, e.g. it could go wrong after about 30 seconds, if one side of the comparison gets cast to an int16_t, somehow.

Since comparisons with millis() or micros() involve modulo (clock) arithmetic, it's generally best to do a subtraction of the last time it had to do something with millis() / micros, and compare that with the interval - but keep it all in unsigned longs, and either specify constants as ul, or use a variable or declare a const to put them in, that's defined as unsigned long.

e.g. instead of

uint32_t lastSerTime;
uint32_t lastKeepAliveTime;
uint16_t interval = 2000;
  if (millis() > lastSerTime + interval) {
// ...
if (millis() > lastKeepAliveTime + 1000) {

Try:

unsigned long lastSerTime;
unsigned long lastKeepAliveTime;

unsigned long interval = 2000;
// ...
  if (millis() - lastSerTime  > interval) {
// ...
if (millis() - lastKeepAliveTime  > 1000UL) {

That may well not be the cause of the problem though :) It's just something to try.

The comparison part is most likely to go wrong if interval isn't automatically cast to an unsigned long, or uint32_t. Doing it as a subtraction instead of an addition is best practice, for modulo arithmetic, but couldn't have any effect before millis() resets / wraps around to zero.

[JoeEarlam]

Unfortunately I don't think it's that simple - initially this behaviour occurred under the TaskScheduler library with no use of millis(), I just threw this example code together as an absolute minimal example.

Also, that doesn't explain why putting a more frequent serial print in a different routine fixes things, nor why making the interval under roughly 2500 milliseconds fixes it but 3000 milliseconds breaks it!

[Andy2No]

Yes, that's certainly mysterious. Does Linux have power saving settings for USB ports? In Windows, it's only on root hubs, IIRC.. and "Generic USB Hub"s, on the Power Management tab for their driver in Device manager. I have that turned off because it can cause problems with USB thumb drives and card readers. It can decide to turn the USB ports off mid file transfer, otherwise.

[JoeEarlam]

I am not sure, however I did check dmesg for kernel messages and nothing relevant shows up.

[earlephilhower]

Check out #1407. There seems to be an Ubuntu kernel thing in some bleeding edge releases that makes serial ports disappear after a delay of a few seconds.

[JoeEarlam]

Thanks! I am using 20.04, indeed with almost the same kernel version as you were using when unable to reproduce the bug, however it's not exactly the same version, and the bug does manifest in a very similar way (I also wouldn't rule out PC hardware bugs). I'll skim some kernel changelogs and try out a few different kernels and see if anything interesting happens.

[earlephilhower]

FWIW I'm on this with no issues. Seems like 1 or 2 rev before yours (I update but seldom reboot)

Linux amd 5.15.0-69-generic #76~20.04.1-Ubuntu SMP Mon Mar 20 15:54:19 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux