Overruns as a result of running logging

Hello everyone,

My team members and I have been setting up wpi’s logging infrastructure for the past few months.
We save all the data in each cycle as a String, and when converted to CSV we divide into cells according to a comma that is printed after each entry of a value.
The controller we use is RoboRio 2.0, with two cores, and we know that the logging infrastructure of wpi ran on a separate thread.
When we activate the logging infrastructure and send values ​​of all robot systems in every run cycle in teleopPeriodic for that matter, we encounter overruns. And the cycle time of teleopPeriodic is greater than 0.02 seconds. When we cancel the logging update, the time cycle of teleopPeriodic decreases significantly and we do not receive overruns from it.

We would be very happy if you would share suggestions about a way to reduce the cycle time of updating the logging.

Thanking you in anticipation,
Learoy, BumbleB.

1 Like

There’s a few things that could contribute that come to mind. Besides writing to files, building strings can be slow, as can reading from HW sometimes. I would try to separate the problem. First thing I’d do is replace each item you’re logging with a random number. This will remove any slow HW calls and you can see how the timing changes. Or you could remove half the items and see if the loop times get cut if half or if they get cut a lot more then half or a lot less then half. If it gets cut in half that would indicate more likely string or file slowness.

My team ran csv logging for several years without any fancy tricks, so that’s why I’m leaning toward HW.

It would help if we could see your code. If using Java, are you using StringBuilder?

1 Like

Why are you doing this? DataLog is designed as a binary format that supports logging individual binary values (think of it like NT in log format), so it’s completely unnecessary to build strings of data in robot code. The easiest option is to simply enable logging of NT (DataLogManager.enableNetworkTables(true)), then everything you put in NT will get logged. If you truly want to only log things and not also put them in NT, see the functions in the DataLog object (that DataLogManager.getLog() returns).

5 Likes

First of all, thank you very much for the response.

We do not save the data in this method, because we could not print all the data in a run cycle. In the proposed method, we send one value in each cycle, so we do not manage to keep the values of all the robot systems in one row.

Thank you very much for your reply, we will definitely try it.

Thanks for your reply !

We are using java. But we don’t use StringBuilder.
I will attach here the piece of code that creates the string, I would appreciate your advice on the subject, or an explanation as to why this method is not efficient enough.

public void update() {
if (isRunning) {
String logData = this.gameDescription + “,” + this.mark + “,”;

        for (Section section : sections) {
            ArrayList<Column> columns = section.getColumns();
            
            for (int i = 0; i < columns.size(); i++) {
                logData += columns.get(i).getStringValue();
                logData += ",";
            }
        }
        logEntry.append(logData);
    }

You might find this Stack Overflow thread useful. Essentially, concatenating strings as you’re doing leads to a lot of allocation and copying. StringBuilder is designed to solve this specific usage pattern much more efficiently.

Of course, I don’t know for certain that string concatenation is actually your biggest problem here, or that switching to StringBuilder will solve all your problems.

1 Like

Thank you very much, it is not obvious at all !

We will certainly look into this, it is really possible that the construction of the string does result in a lot of allocation and copying.

Specifically, you want to use a StringBuilder created outside of the loop. The java compiler uses StringBuilder for string concatenation. The java compiler will compile the code you posted and create a new StringBuilder each iteration of the loop.

There is also a bug in Java that causes poor string concatenation performance on the first call, but that should be mitigated with a change to the java compiler arguments added to the 2023 build.gradle generated by vscode.

1 Like

I think I understand what you’re saying–you’re looking for a bunch of separate data values (e.g. from a subsystem) to appear as a single row in the output from datalogtool. Currently datalogtool always outputs one row per data value, but one of the feature improvements I’d like to make is to have a setting for some “fuzziness” on timestamps to merge the results into columns of a single row. Since you can set timestamps when you set values to NT and datalogtool, it could be made even more robust by setting all the values with the same timestamp.

2 Likes

Thank you,
Could it be so significant in terms of cycle time periodically ?