Add loop timing telemetry

[PeterJohnson]

It would be useful for users to know loop timing of various pieces of their code. This should be published via NT so it can be recorded and played back on the dashboard. For command based this could be pretty fine-grained.

[gerth2]

Could this also be exposed through an API inside user software? Being able to read it directly (rather than only NT) would be useful to us.

[auscompgeek]

@gerth2 One can already read directly from NT on the robot (without having to wait for updates), so that shouldn't be a problem.

[virtuald]

Yeah, I've been bit by this sort of thing a lot. It would be good to do this.

[gerth2]

Would a histogram of execution times be useful as well? Definitely wouldn't be needed at first-pass, but our team would find use in it.

[auscompgeek]

@gerth2 if you have a NT client that logs the values as they are updated, you could rather easily use your favourite data analysis tools to create a histogram from that.

[gerth2]

@auscompgeek makes sense!

[Starlight220]

Hasn't this been resolved by the Tracer class PRs? If teams want to post the data to NT they can use the overload that accepts an output lambda. Perhaps something should be added to frc-docs about it, but I think this is resolved. If it isn't, then what needs to be done should be cleared up.

[auscompgeek]

My understanding is that there is still no fine-grained timing telemetry for the command scheduler, which would definitely be desirable.

[Starlight220]

There is a Watchdog instance used in CommandScheduler, though I don't think there's any user-facing API for receiving the printed epochs (they're printed directly in case of loop overrun). Is there anything else needed?

[calcmogul]

What's implemented now doesn't address the intent of the original post. The idea is that Tracer data would be published to NetworkTables so teams can easily see it on every loop iteration (well, it gets actually sent out at 100ms by NT and intermediate values are dropped, so network I/O shouldn't be too bad).

Watchdog only warns on overruns, but it's useful to know how much of the timing budget you're using in nominal cases too. Having more information like this makes it easier to optimize or find performance concerns early and fix them. (In other words, "the first rule of performance is to measure".)

[Starlight220]

So perhaps a method in CommandScheduler that logs a listener that receives the Tracer data at the end of each loop? Then teams are free to do whatever they want with that data, including sending it over NT in a format that they prefer. Would this address the OP?

[prateekma]

For C++, you could create a simple ScopedTracer class (that either inherits Tracer or uses composition) such that the timer begins when the object is constructed (with an NT entry as a parameter) and the timer ends (and data is published) when the object is destroyed.

void Periodic() {
  frc::ScopedTracer timer(m_telemetryEntry);
  ...
}

[Starlight220]

Why can't C++ get the same treatment as Java and just have the data published to a listener?

[prateekma]

Why can't C++ get the same treatment as Java and just have the data published to a listener?

You can create a similar version of a ScopedTracer that takes a listener instead; perhaps a secondary constructor that takes an NT entry for those who don't want to deal with that.

The main point I was trying to make was that it would be nice for the C++ variant to be scoped so that teams wouldn't have to call start() and stop() manually (or whatever the API ends up being for Java).

[Starlight220]

You missed my point. I think that the team can (and should) be responsible for posting the data to wherever they want, whether it be NT, reportWarning(), or any other data logging format a team has. We accept a listener and give it the data. The rest is the team's responsibility; assuming they want the data.

[prateekma]

I think that the team can (and should) be responsible for posting the data to wherever they want, whether it be NT, reportWarning(), or any other data logging format a team has.

Yes, I agree. As I pointed in my last comment, the primary constructor should be a listener, but we can have a secondary constructor that takes in an NT Entry (which calls the primary constructor internally) because that is a common use case and specifically requested by the OP.

[Starlight220]

I want to avoid the middleman "dummy" class - just have an overload that takes an NTEntry, and calls the lambda overload with entry.putString() or whatever.