Robot commands delay on FMS

[Brunoo1103]

Hey, after we finished competing the regional, I want to know why our robot had command delay while playing in FMS connection

Robot specs:

RoboRIO 1
4 VictorSP on drivetrain
2 VictorSPX & 1 TalonSRX on other subsystems
WPILib version 2022.4.1

What is the problem:

When we worked on programming in build season, the robot looked like ok. No lagging or delays when using the robot with wireless connection with Driver Station. We did not check any logging or memory usage of the RoboRIO.

In the competition (Bosphorus Regional), we started to use the robot on practices and noticed random delay issues in the middle of the match. For example: Out of nowhere I move the drivetrain forward, but the robot does not move instantly, it takes 1 or 2 seconds to respond but very strange responses. The same with shooter and intake. The robot become useless.

On the final of practices, we tried to remove all “useless” code, like constructing autonomous Trajectories that we would not use in the competition, and sensors that could not be calibrated on completion for usage.

For the second day, I noticed that I had less frequently delay, just 1 or 2 time (7 to 10 seconds delay) per game.

We moved on to the third day, in qualifications: We managed to pass to semi final with only 1 delay on quarter finals. We thought we this problem would be trivial. However, in semis, we just let our robot for 2 matches stopped, since all the two matches we couldnt even move the drivetrain properly (we did not lose communication!). Because of the this, we lost the competition.

Now, after this, we wanna know why it happened. We have 3 thoughts:

Root of the problem may be RoboRIO out of memory

• For some reason, autonomous using pathweaver software just killed the memory.

• We run multiple parallel commands for each routine of a cargo collected and shooted (3 parallel commands to collect, 3 parallel commands to organize the cargos inside robot, 3 parallel commands to shoot). This could have killed the memory usage.

• Finally, we noticed after the competitions we let many variables listening on shuffleboard. If we had 20 variables updated every 20ms and sent it to SmartDashboard, we have much changes on the background for no reason.

NOTE: We noticed this problem only on FMS. For now I don’t have the access to robot logging neither can’t test it. This is just a discussion to try thinking about it.

If someone have suffered this like my team I would like to know your vision.

[Ryan_Blue]

This sounds like there was some serious latency on the field network. Could you post your DS logs from the affected matches?

[Mark_McLeod]

The log files on your Driver Station laptop are at: C:\Users\Public\Documents\FRC\Log Files
Find the date-time stamp of the matches in question, then post both the .dslog and .dsevents files with that timestamp.

When you look at your logs also check for this line. It’ll give you your roboRIO disk/memory usage as well as the DS laptop CPU % and battery condition.
Several of those can affect response.

[bovlb]

It has been our experience that SmartDashboard code that reports data from CAN devices (e.g. Spark MAXes) causes loop overrun, but opinions differ.

You should check DS logs for CAN utilization. If that’s your problem, then you may be able to mitigate it by increasing status frame periods on motors that are less time-critical (e.g. followers, intake, shooter).

[Brunoo1103]

match_delay_logs.zip (96.3 KB)

Sorry for responding late. Here is the logs of our last match, which we suffered to control the robot

[Mark_McLeod]

So from the log it looks like user code is taking way too long to process.

This is a close up of just a small time slice of the top of the log.

• The top line of dots (only two dots are visible in this close up) is the user code running on the RIO reporting what match mode it is in (Teleop in this case) to the Driver Station (hover over the dot in the log viewer to see what it is).
• The second row of dots is the Driver Station reporting the mode it is in to this same log.

These Driver Station dots represent the standard FRC 20ms command packet processing rate.
There should be a blue dot from the user code for every blue dot posted by the Driver Station, if the user code is processing at the 20ms rate.
The user code is so slow that it’s only able to return one command packet for every 31 command packets that the Driver Station is sending it.

The green dots below those are periodic warnings that the Command Scheduler is taking too long. And there are some Safety warnings that are cutting power to your drive motors, because they aren’t getting updated often enough.

Generally, this just means you have something slowing down your code like a loop, or that it’s just trying to do too much at once.
It looks like the slow down kicks in about 30 seconds into the match-before then it looks normal. If you can remember (or check video) to see what your robot started to do at that time it’ll be a clue.
At that same time the log also shows the RIO CPU % (red line in the log viewer graph) going from a normal 40% up to about 75%, so some intensive processing started then. It isn’t too much for the RIO CPU to handle, so it isn’t that. It’s just the user code is taking too long processing commands.

Your rio memory looks fine, so it’s not a memory problem as you theorized.
And your laptop looks to be fine, too.

[bovlb]

If you could post your code (say on Github) we could take a look and see if there’s any obvious slowdowns there.

Also, it might help if you could point us at video of the match that goes with these DS logs.

[Brunoo1103]

code on github (branch main): GitHub - Team1772/frc-2022

Semi final 2 - https://www.youtube.com/watch?v=j5hHItdoDXY
NOTE: this game (semi final 2) is not the same log that I sent (match_delay_logs.zip) which was semi final 4. The video from Semi final 4 had connection issues and we can’t see anything when trying to watch.

logs semi final 2: match_delay_semi_final_2.zip (89.0 KB)

video on second 0:03: we are this robot

video on second 0:36: the robot started to delay every command (we couldnt move properly)

Just to compare, on quarter finals we had much delay on game, but we could at least make points. (You noticed that sometimes the robot is trying to think what to do, and it stays stopped) if you wanna watch to compare quarters and semis

Another note: In any time we didnt change any code between quarters and semis

quarter final 4: https://www.youtube.com/watch?v=WWV5KHCy_qo

video on second 0:03: We are this robot

[Peter_Johnson]

One thing I noticed is you’re using the color sensor on the onboard I2C port in your Intake subsystem. There’s a known issue documented for the onboard port which can result in a complete system lockup, but several teams have also reported long delays in reading from either I2C port. The known issues page has some links to alternatives such as using a Pi Pico.

[Brunoo1103]

Hey, thanks for this answer. We had this knowledgment of I2C port on the first day of competition, so we stopped using the color sensor on the code, however, the color sensor was still plugged on I2C port, probably reading values on background. It was a lack of attention from us.

[Peter_Johnson]

I’ll need to double-check, but I don’t believe it reads values in the background. So if you’re never calling it, it shouldn’t be the cause. I’ll keep looking.

Actually, it probably puts itself on LiveWindow for telemetry, so it probably is getting read just from being instantiated in the code. We are re-evaluating automatic LiveWindow telemetry for future seasons for this and other reasons.

[Brunoo1103]

Another thing that I remembered just now:

When programming, our robot always had the problem of “Differential Drive: Output update not often enough”. But it didn’t affect the robot when testing it

I just dont know why it happens because our robot always had this, 2020, 2021, 2022

[Peter_Johnson]

If you only see that message once or twice when first starting up, it’s not an issue–in Java, the first iteration always takes a bit longer as classes get loaded etc. It’s only really a concern if you see it much more frequently.

[Brunoo1103]

Yeah our robot frequently throws this warning if Im not mistaken.

This warning started on the first week of programming, when we were just coding the drivetrain. Do you know why it happens?

the code (branch main): https://github.com/Team1772/frc-2022 (It may be something related to drivetrain)

No problems when testing on our HQ in wifi, but on FMS may have issues

[bovlb]

Beyond the I2C issue that @Peter_Johnson has already mentioned, I don’t see any major issues in your code. Some minor notes that are probably not your main issue:

• There’s some odd code in RobotContainer where you call buttonA.get(), ​​this.operator.getRightTriggerAxis(), and new ScheduleCommand. I don’t think this will behave the way you expect, as these aren’t normally usable within the constructor.
• I recommend that you use getAutonomousCommand with a SendableChooser. Are you redeploying code just to change the autonomous routine?
• You can use withTimeout to get a timer version of an existing command.

You said that you only have problems on FMS. Have you tried using test mode, and driving teleop after running your auto?

[bovlb]

I’ve had a look at your event log. I’m seeing lots of loop overrun messages that say that Intake.periodic() is taking nearly 500ms (out of a total budget of 20ms). That’s enough by itself to make the robot extremely unresponsive. As the only thing this method is doing is to check the color sensor (five times) and send the results to the SmartDashboard, I’m now convinced that @Peter_Johnson is right, and this is the I2C problem.