Mysterious behavior/failure using delay() while receiving data over USB

collinATculture · Apr 15, 2020

I was experiencing strange behavior in a project and was able to boil it down into this simplified version to demonstrate the issue. I'm running the code below on a teensy3.6, connected over USB on OSX. I'm flashing with platformIO and also using PIO for serial communications in terminal.

If you send one line containing "Hello World" the program below outputs the expected block of text:

------ Printing Your Message --------
Message Content: Hello World
Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

However, if you copy two or three (or more) lines of "Hello World" from your favorite text editor:

Hello World
Hello World

The first (and only the first) text block often aborts midway through, resulting in output like this:

------ Printing Your Message --------
Message Content: Hello World
Delayed 100 microseconds
Delayed 250 microseconds
Delaye------ Printing Your Message --------
Message Content: Hello World
Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

I've been struggling to understand what can be happening here in such a simple example. I've seen the higher level problem that led me to this boiled-down version on multiple teensy3.6's, including raspberry pi's over USB, and also when using a python sketch to more carefully control whether I'm terminating my messages with \r, \n, or both. Any idea what's going on here? Is there some timing issue that I'm not aware of? Should I be adding some delay between lines from the transmit side? Any help is much appreciated, this has been plaguing me for a couple months now and I keep coming back to it without success (finally decided to post now that I have a simple demo of the issue).

The main.ino file:

Code:

void setup() {
  Serial.begin(115200);
}

void loop() {
  // Check for new messages
  handleMessages();
}

void handleMessages() {
  while (Serial.available()) {  
    // Get a newline-terminated line from USB serial
    const int maxMessageLength = 200;
    char message[maxMessageLength];
    // Line terminator can be \n or \r\n
    Serial.readBytesUntil('\n', message, maxMessageLength);

    Serial.println("------ Printing Your Message --------");

    Serial.print("Message Content: ");
    Serial.println(message);

    delayMicroseconds(100);
    Serial.println("Delayed 100 microseconds");

    delayMicroseconds(250);
    Serial.println("Delayed 250 microseconds");

    delayMicroseconds(500);
    Serial.println("Delayed 500 microseconds");
    
    delay(1);
    Serial.println("Delayed 1 milliseconds");

    delay(10);
    Serial.println("Delayed 10 milliseconds");

    delay(100);
    Serial.println("Delayed 100 milliseconds");

    Serial.println("------ End of Message --------");
    Serial.println();
  }
}

Using a platformio.ini file here, in case it matters:

Code:

[env:teensy36]
platform = teensy
framework = arduino
board = teensy36

luni · Apr 16, 2020

Tested your sketch. It works perfectly here (Win10, TyTools). I used the tyCommander to send a file with the following content:

Code:

Hello World 1
Hello World 2 
Hello World 3
Hello World 4
Hello World 5
Hello World 6

And get the following printed in the tyCommander monitor:

Code:

------ Printing Your Message --------
Message Content: Hello World 1

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

------ Printing Your Message --------
Message Content: Hello World 2 

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

------ Printing Your Message --------
Message Content: Hello World 3

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

------ Printing Your Message --------
Message Content: Hello World 4

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

------ Printing Your Message --------
Message Content: Hello World 5

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

------ Printing Your Message --------
Message Content: Hello World 6

Delayed 100 microseconds
Delayed 250 microseconds
Delayed 500 microseconds
Delayed 1 milliseconds
Delayed 10 milliseconds
Delayed 100 milliseconds
------ End of Message --------

I don't know how you send/receive the data on the PC side but it might well be that your PC software has problems sending / receiving data at the same time?

defragster · Apr 16, 2020

Teensy powers up and set things right to enable needed clocks and peripherals - does an init on USB and the waits until the clock has been running 300 ms and then calls setup()

Arriving in setup() at this point there may be another 30-300+ ms needed for the PC to establish the connection if SerMon is actively waiting.

Any printing in that time is suspect and may not even make it to the bit bucket. Though sometimes by luck it gets buffered and display up to a point … as observed in p#1

If you want to be sure to allow computer connect time put code like this before any print that should be seen:

Code:

void setup() {
	[B]while (!Serial && millis() < 4000 );[/B]
	Serial.println("\n" __FILE__ " " __DATE__ " " __TIME__);
  // ...

That will wait until the Teensy has been started for 4 seconds - the time is optional or adjustable - 4 seconds allows time to open a SerMon session if needed. If it connects sooner it will begin then.

The other way to wait forever for USB Serial to connect is :: while (!Serial );

But that can cause trouble starting if the data isn't critical to read and USB may not always be connected.

And a bonus useless tidbit the "Serial.begin(115200);" does nothing on Teensy as USB will be started before setup() is called as noted when compiled with that specified. This is because Teensy USB is provided by processor Native USB hardware - not an intermediate chip needing to know th ebaud rate. Teensy uses the fastest usable USB connect the computer offers which on a T_3.6 should be 12 Mbps like the other ARM Teensys, except the T_4.x family hardware is 480 Mbps capable.

collinATculture · Apr 16, 2020

Thank you luni for trying on another machine! Something must be amiss with my setup I guess. I'm able to repeat the bug multiple times in a row, even if I leave the serial window open for >30s before I start sending anything. I took out the Serial.begin() and added a 5000ms delay in setup instead, but no changes to the behavior. I'm noticing that it almost always breaks at the exact spot I highlighted about, after the 'e' in "Delayed 500 microseconds" which makes me think it might be timing related. I tried a longer message and it fails in one of two different new spots, one midway through a print, and the other after a complete line (presumably during the following delay).

luni · Apr 16, 2020

I'm quite sure that this has nothing to do with the sketch or your machine. I suggest to install tyTools (https://github.com/Koromix/tytools/releases) send a file with a few "Hello World lines" and try if it works with that. If it works you can be sure that the Teensy sketch and your setup works ok.

defragster · Apr 16, 2020

The code change in p#3 should work to get that line out - reading into loop() seeing the .available() suggests that would only work when it would pass that test.

TyCommander is the best tool as @luni suggests give that a try as SerMon. If the IDE is already installed use the Teensy_ports SerMon from there and compare the results.

luni · Apr 16, 2020

If the IDE is already installed use the Teensy_ports SerMon from there and compare the results.

I don't use that often, can the IDE SerMon send files? If not, you can not reproduce the problem I'm afraid.

defragster · Apr 16, 2020

I avoid the IDE too - with TyCommander ( aka:tyqt )

Had to open IDE and confirm it does not offer Send File like TyComm does - install and test with that - it is Awesome.

collinATculture · Apr 16, 2020

Installed TyCommander and confirmed the bug is not present using it's serial monitor. Thanks for the assist, sorry it was a bit of a false alarm. I suppose the issue is with platformio's serial handling?

defragster · Apr 16, 2020

"issue is with platformio's serial handling? " - sounds like the problem.

T_3.6 is only 12 Mbps - but very fast and efficient at it. TyComm is as fast or faster than IDE SerMon in general - and Paul had to work to get IDE SerMon version that could keep up with Fast Teensy - versus Serial converters from AVR chips < 1 Mbps versus the 12 Mbps.

Fun thing is the T_4.0 at 480 Mbps required a lot more work to keep up with that as well as the computer can deliver the data and still the computer is the slow side needing work.

Mysterious behavior/failure using delay() while receiving data over USB

collinATculture

New member

luni

Well-known member

defragster

Senior Member+

collinATculture

New member

luni

Well-known member

defragster

Senior Member+

luni

Well-known member

defragster

Senior Member+

collinATculture

New member

defragster

Senior Member+