Added option to prefix serial monitor messages with a timestamp. #1189

dajtxx · 2020-05-25T01:06:59Z

This commit adds the option to print a timestamp before each line received over the serial port. There is a new button in the serial monitor to switch it on and off. The time used is local time.

This mode won't work well if the sketch isn't regularly sending EOL sequences as it waits for them before flushing the received data. The logic to keep flushing based upon how much data was stored seemed to be difficult and messy for an edge case so I decided to make this compromise.

One sort-of-unrelated change adds EOL to the message saying no serial devices are connected so that the timestamp on the connection message starts on a new line.

jantje · 2020-05-25T10:45:54Z

Have you tested this with multiple arduino's connected all sending data at the same time?
From your description the behaviour is going to be pretty different.

dajtxx · 2020-05-25T10:51:41Z

No, good point. I'll see what I can do.

io.sloeber.ui/src/io/sloeber/ui/messages_nl.properties

jantje · 2020-05-25T11:32:21Z

io.sloeber.ui/src/io/sloeber/ui/monitor/internal/SerialListener.java

+		private StringBuilder lineBuffer = new StringBuilder();
+
+		private DateTimeFormatter timeFormatter = DateTimeFormatter.ofPattern("HH:mm:ss"); //$NON-NLS-1$
+		private static final String arduinoEOL = "\r\n"; //$NON-NLS-1$


It looks to me as if you are assuming arduino always sends \r\n as newline. This is however not true.
\n is a safer option.

I did wonder about this.

How about I discard all \r and match on \n. A simple implementation of that might be slow but I'll see how it goes.

I quite often use String.replace ("\r\n","n");
However in this case I don't really like it because you can save the monitor content for later processing and then the user may not get what he wants.

jantje · 2020-05-25T11:38:36Z

io.sloeber.ui/src/io/sloeber/ui/monitor/internal/SerialListener.java


 		public synchronized void addData(String event) {
 			if (!event.isEmpty()) {
-				this.additionalSerialData = this.additionalSerialData + event;


wouldn't it be easier to have something like

if (SerialListener.showTimestamps) { String ts = LocalTime.now().format(timeFormatter) + ": "; //$NON-NLS-1$ this.additionalSerialData = this.additionalSerialData + event.replace('\n',ts ); } else{ this.additionalSerialData = this.additionalSerialData + event; }

I tried that but it wasn't reliable. I can't tell you why because it looks like it should work but it didn't. I still got line breaks in weird places, it was like they were being added by something else but I can't think what. It made no sense, but it didn't work.

The code in the pull request is the only one of 3 or 4 different algorithms I tried that seems to work consistently.

Thinking about this.... I think it is way better to add this code in the monitor itself
SerialMonitor.ReportSerialActivity
go from
public void ReportSerialActivity(String stInfo, int style) {
int startPoint = monitorOutput.getCharCount();
monitorOutput.append(stInfo);
StyleRange styleRange = new StyleRange();
styleRange.start = startPoint;
styleRange.length = stInfo.length();

to
public void ReportSerialActivity(String stInfo, int style) {
int startPoint = monitorOutput.getCharCount();
String displayInfo;
if (SerialListener.showTimestamps) {
String ts = LocalTime.now().format(timeFormatter) + ": "; //$NON-NLS-1$
displayInfo= stInfo+ event.replace('\n',ts );
}
else{
displayInfo= stInfo;
}

monitorOutput.append(displayInfo); StyleRange styleRange = new StyleRange(); styleRange.start = startPoint; styleRange.length = displayInfo.length();

dajtxx · 2020-05-25T11:56:11Z

It worked ok with two devices. There doesn't seem to be any thread safety around SerialMonitor.ReportSerialActivity though - could the Eclipse text control have thread safety in it?

It might be worth making the SerialMonitor.ReportSerialActivity method synchronized to be sure, but I'm not seeing a problem without synchronized.

I wonder what effect the timestamping code would have on your scope function? Would the buffering until EOL break that?

I'm testing with the code below. With timestamps on the messages show up nicely. With timestamps off the messages get interleaved due to the delay in the two part message.

This is actually an Uno and a M0 Feather, sadly you can't see the colours! 100s of lines like this:

21:38:14: Uno wrote this whole line message.
21:38:14: Uno wrote this two part message.
21:38:14: Uno wrote this whole line message.
21:38:14: Uno wrote this two part message.
21:38:14: Uno wrote this whole line message.
21:38:14: Uno wrote this two part message.
21:38:14: Uno wrote this whole line message.
21:38:14: Uno wrote this two part message.

Then I switch off the timestamps. This interleaving is expected due to the way the original code works.

21:38:15: Uno wrote this whole line message.
21:38:15: Uno wrote this two part message.
Uno wrote this Uno wrote this whole line message.
two part message.
Uno wrote this Uno wrote this whole line message.
two part message.
Uno wrote this Uno wrote this whole line message.
two part message.
Uno wrote this Uno wrote this whole line message.
two part message.
Uno wrote this Uno wrote this whole line message.
two part message.

int i = 0;
// The loop function is called in an endless loop
void loop()
{
	if (i == 0) {
		Serial.println("Uno wrote this whole line message.");
		i = 1;
	} else if (i == 1) {
		Serial.print("Uno wrote this ");
		i = 2;
	} else if (i == 2) {
		Serial.println("two part message.");
		i = 0;
	}
	delay(100);
}

jantje · 2020-05-25T13:47:31Z

It worked ok with two devices. There doesn't seem to be any thread safety around SerialMonitor.ReportSerialActivity though - could the Eclipse text control have thread safety in it?

There is:

I wonder what effect the timestamping code would have on your scope function? Would the buffering until EOL break that?

That is why prefer it in the monitor class. At least there you know \n is a newline and not some binary data

Then I switch off the timestamps. This interleaving is expected due to the way the original code works

Yes and that is the way it is supposed to be. This is why I commented with "From your description the behaviour is going to be pretty different.'
If you are trying to debug inter arduino communication that is not line driven you want the info interlaced. This is also why I added the colour to the serial channel so you can clearly see where the data is coming from.

dajtxx · 2020-05-26T01:49:58Z

I've done some more exploring and changed my test sketch to include some plotter data.

There is SerialListener and PlotterListener, which run in "parallel" in that they don't share data. So any change made to SerialListener won't affect the actual plotted data, but it still might not be the right place for my change - I think you're right and SerialMonitor is where it should go.

What does this code do in SerialListener.internalMessage? It's triggered when not filtering the plotter data from the incoming bytes.

else {
	// treat data just like a event
	if (newData[newData.length - 1] == '\r') {
		newData[newData.length - 1] = ' ';
	}
	ret = (new String(newData));
}

If the plotter data is not filtered then the String passed to the serial monitor can still contain \r\n as part of the plotter data - my sketch is sending 0xCDAB 0x0002 0x0D0A and I'm getting newlines in the output where-ever the plotter data shows up.

dajtxx · 2020-05-26T02:09:13Z

Here is what happens when you don't buffer up the incoming messages into lines. If the SerialMonitor is where the change is made it will have to do the buffering. That means the color index bug I found yesterday will have to be fixed too or the data could all go into one device's buffer.

If the plotter data is not being filtered and contains \r\n it will cause unwanted newlines and timestamps but that doesn't worry me because I don't use the plotter.

jantje · 2020-05-26T11:16:34Z

I don't know which code you used but this piece of code I proposed is wrong causing things to look wierd

String ts = LocalTime.now().format(timeFormatter) + ": "; //$NON-NLS-1$
displayInfo= stInfo+ event.replace('\n',ts );

it should be something like

String ts = LocalTime.now().format(timeFormatter) + ": "; //$NON-NLS-1$
displayInfo= stInfo+ event.replace('\n','\n'+'ts );

This way the timestamp should always be followed by content of the same colour (unless the \n is the last char)

jantje · 2020-05-26T11:24:56Z

Some background info.
The serial monitor code is very complex. This is because it supports multiple serial connections of which the first one can be binary data.
Binary data is send using the simplot library
https://github.com/jantje/ArduinoLibraries/blob/master/simplot/examples/plotterExample/plotterExample.ino#L33
Plotter data is recognized by the 0XAB 0XCD sequence followed by the number of bytes to be read.
This data can be filtered in the serial monitor.
Both the Serial monitor and the Plotter get all data. So in the serial monitor you can not assume everything is text.

jantje · 2020-05-26T11:32:22Z

Seems I missed part of what you typed in my previous comment ;-)

If the plotter data is not filtered then the String passed to the serial monitor can still contain \r\n as part of the plotter data - my sketch is sending 0xCDAB 0x0002 0x0D0A and I'm getting newlines in the output where-ever the plotter data shows up.

The only reason to not filter the plotter data is for testing to see whether binary data arrives or not.
I don't think it is useful to try to represent the binary data properly in text format. Especially as it is really easy to do both binary and textual in the sketch.
Like I do in the example
https://github.com/jantje/ArduinoLibraries/blob/master/simplot/examples/plotterExample/plotterExample.ino#L34

jantje · 2020-05-26T11:41:10Z

What does this code do in SerialListener.internalMessage? It's triggered when not filtering the plotter data from the incoming bytes.

If I remember correctly avoid you get 2 newlines when a \r\n is split in the middle

…ugin

dajtxx · 2020-05-26T22:56:45Z

I have updated my change so it uses the serial port index fix and the time-stamping happens in SerialMonitor.

I'm guessing the conflict mentioned above is caused by the fact I redid the serial port index fix in my fork before the pull request was merged and the fix could be brought in that way.

I am still buffering lines because I want to avoid messages from multiple serial ports appearing on a single line. If I was using this feature I would write my sketches so their log messages all end with an EOL and I'd want to read them as complete lines without some other message appearing halfway through the line due to serial driver delivery timing.

jantje · 2020-05-27T09:47:28Z

io.sloeber.ui/src/io/sloeber/ui/monitor/internal/SerialListener.java

 		private String additionalSerialData = new String();

 		public synchronized void addData(String event) {
-			if (!event.isEmpty()) {


I think this line should not be deleted?
Shouldn't we just restore SerialListerner?

Sorry about that! I've pushed a commit to fix it, but even better would be to just throw away all changes to SerialListener as you suggest. But I don't know enough about git to do that - how would I do it?

jantje · 2020-05-27T10:30:40Z

I think I can resolve the conflict (probably cause by something wierd as it is just a added line)
Can you restore SerialListerner.java?

jantje · 2020-05-27T13:21:00Z

Hope this worked ok.

dajtxx · 2020-05-28T00:16:44Z

I mucked about with git reset and git revert to try and take my master branch back to when I first forked, but couldn't get anything to work. Sorry the history on the files is a bit messy now.

jantje · 2020-05-28T00:30:08Z

Don't worry I did some things wrong and had to fix after the merge
Should be available tomorrow on the nightly though :-)

Added option to prefix serial monitor messages with a timestamp.

3e9d337

jantje reviewed May 25, 2020

View reviewed changes

io.sloeber.ui/src/io/sloeber/ui/messages_nl.properties Show resolved Hide resolved

jantje reviewed May 25, 2020

View reviewed changes

dajtxx added 2 commits May 26, 2020 18:34

Most of the timestamp changes, minus SerialListener.

8b208ec

Timestamping working.

bebfb1b

dajtxx added 4 commits May 26, 2020 21:52

Create timestamp_console.png

7199670

Brought up to date with upstream.

c167aa1

Merge branch 'master' of https://github.com/dajtxx/arduino-eclipse-pl…

9617374

…ugin

Still bringing things into sync.

8f73472

jantje reviewed May 27, 2020

View reviewed changes

dajtxx and others added 2 commits May 27, 2020 21:38

Put back missing test for an empty message.

b15f437

Merge branch 'master' into master

83c230d

jantje merged commit 2eafa6d into Sloeber:master May 27, 2020

Added option to prefix serial monitor messages with a timestamp. #1189

Added option to prefix serial monitor messages with a timestamp. #1189

Uh oh!

Conversation

dajtxx commented May 25, 2020

Uh oh!

jantje commented May 25, 2020

Uh oh!

dajtxx commented May 25, 2020

Uh oh!

Uh oh!

jantje May 25, 2020

Choose a reason for hiding this comment

Uh oh!

dajtxx May 25, 2020

Choose a reason for hiding this comment

Uh oh!

jantje May 25, 2020

Choose a reason for hiding this comment

Uh oh!

jantje May 25, 2020

Choose a reason for hiding this comment

Uh oh!

dajtxx May 25, 2020

Choose a reason for hiding this comment

Uh oh!

jantje May 25, 2020

Choose a reason for hiding this comment

Uh oh!

dajtxx commented May 25, 2020

Uh oh!

jantje commented May 25, 2020

Uh oh!

dajtxx commented May 26, 2020

Uh oh!

dajtxx commented May 26, 2020

Uh oh!

jantje commented May 26, 2020

Uh oh!

jantje commented May 26, 2020

Uh oh!

jantje commented May 26, 2020

Uh oh!

jantje commented May 26, 2020

Uh oh!

dajtxx commented May 26, 2020

Uh oh!

jantje May 27, 2020

Choose a reason for hiding this comment

Uh oh!

dajtxx May 27, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

jantje commented May 27, 2020

Uh oh!

jantje commented May 27, 2020

Uh oh!

dajtxx commented May 28, 2020

Uh oh!

jantje commented May 28, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

dajtxx May 27, 2020 •

edited

Loading