Serial monitor prints data with the wrong timestamp

[silvanocerza]

Describe the bug

The Serial Monitor doesn't print the value just received with the correct timestamp but with the one of the previous received value.

If the board sends A at time 1 and B at time 2 this would be the output, first:

1 -> A
1 ->

then:

1 -> A
1 -> B
2 ->

Changing the baud rate to a lower or higher one doesn't change a thing.

To Reproduce
Steps to reproduce the behavior:

1. Create a Sketch with the following code:

void setup()
{
  Serial.begin(2400);
  while (!Serial);
}

void loop()
{
  static byte x = 0;
  Serial.println(x);
  delay(10000);
  x++;
}

2. Upload it to your board
3. Open the Serial Monitor
4. Set the baud rate to 2400
5. Click Toggle Timestamp if not already on

Notice how the timestamp for the value printed now is not correct but reference to the previous one.
Also the first value is printed two times.

Expected behavior

I expect the values to be printed on the correct timestamp when it's received by the PC.

Screenshots

issue.mp4

Desktop (please complete the following information):

• OS: Linux
• Version: 2.0.0-beta.7

Additional context

This issue has been original reported on the Arduino Forum: https://forum.arduino.cc/t/serial-monitor-gives-wrong-time-stamp

[kittaakos]

Maybe it is unrelated, but why does the CLI send \r\n with Serial.println? I am on macOS. Was it always like that? This is what I get from the CLI:

root INFO server on data: |1| ascii: 49 bin: 110001
root INFO server on data: |
| ascii: 13 bin: 1101
root INFO server on data: |
| ascii: 10 bin: 1010
root INFO server on data: |2| ascii: 50 bin: 110010
root INFO server on data: |
| ascii: 13 bin: 1101
root INFO server on data: |
| ascii: 10 bin: 1010
root INFO server on data: |3| ascii: 51 bin: 110011
root INFO server on data: |
| ascii: 13 bin: 1101
root INFO server on data: |
| ascii: 10 bin: 1010
root INFO server on data: |4| ascii: 52 bin: 110100
root INFO server on data: |
| ascii: 13 bin: 1101
root INFO server on data: |
| ascii: 10 bin: 1010

I changed this locally to get the log 👆:

diff --git a/arduino-ide-extension/src/node/monitor/monitor-service-impl.ts b/arduino-ide-extension/src/node/monitor/monitor-service-impl.ts
index 86c5df1..b85e6cd 100644
--- a/arduino-ide-extension/src/node/monitor/monitor-service-impl.ts
+++ b/arduino-ide-extension/src/node/monitor/monitor-service-impl.ts
@@ -94,6 +94,9 @@ export class MonitorServiceImpl implements MonitorService {
         duplex.on('data', ((resp: StreamingOpenResponse) => {
             const raw = resp.getData();
             const message = typeof raw === 'string' ? raw : new TextDecoder('utf8').decode(raw);
+            const toBin = (s: string) => s.split('').map(c => c.charCodeAt(0).toString(2)).join(' ');
+            const toAscii = (s: string) => s.split('').map(c => c.charCodeAt(0)).join(' ');
+            console.log(`server on data: |${message}| ascii: ${toAscii(message)} bin: ${toBin(message)}`);
             this.messages.push(message);
             this.onMessageDidReadEmitter.fire();
         }).bind(this));

[CptHolzschnauz]

I like to add a little beautify suggestion:

The time is avtual stamped in format (example) 9:3:55.877
I suggest the form : 09:03:55.877