New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Slow loops with Copter 3.5 and 3.6 on Pixhawk 2.0 and 2.1 #7060

Closed
Pedals2Paddles opened this Issue Oct 10, 2017 · 11 comments

Comments

Projects
None yet
5 participants
@Pedals2Paddles
Contributor

Pedals2Paddles commented Oct 10, 2017

Issue details

On multiple people's Solos running AC 3.5.0+ or 3.6-dev (all unmodified, straight off the build server) on both Pixhawk 2.0 Pixhawk 2.1 autopilots, we're seeing slow loops detected by the log analyzer. It is consistently happening to everyone that goes looking for it. The number of slow loop lines and % varies each time though.

Some examples of the slow loop reports:
Test: PM = FAIL - 31 slow loop lines found, max 55.06% on line 102351
Test: PM = FAIL - 64 slow loop lines found, max 19.77% on line 64050

One user reported the copter shut down twice about 2 seconds after takeoff, and the log abruptly ended prior to whatever error or incident caused it. It unknown if that's related to the slow loops or not, since the slow loops have apparently been happening for months without incident. It could just as easily have been a power issue or some unknown operator error too. But worth mentioning.

Are we seeing a real problem here? Or is this something to be expected and ignored? If the latter, the log analyzer should probably be updated to not show this as a fail. If the former...??

I attached a dataflash log of a quick run up on the bench with slow sloops detected.

Version

Copter 3.5 and 3.6-dev

Platform

[ ] All
[ ] AntennaTracker
[X] Copter
[ ] Plane
[ ] Rover
[ ] Submarine

Airframe type

Solo

Hardware type

Pixhawk 2.0 and 2.1

Logs

Matt's 3.6-dev slow loop.zip

@rmackay9

This comment has been minimized.

Show comment
Hide comment
@rmackay9

rmackay9 Oct 13, 2017

Contributor

I think there are nearly always some slow loops. numbers like 31 and 64 shouldn't be a problem because it's out of a total of 4000 for the 10 second period that is reported upon.

I think it's very unlikely that the shutdown was related. It's much more likely to be a hardware issue like a power failure.

Contributor

rmackay9 commented Oct 13, 2017

I think there are nearly always some slow loops. numbers like 31 and 64 shouldn't be a problem because it's out of a total of 4000 for the 10 second period that is reported upon.

I think it's very unlikely that the shutdown was related. It's much more likely to be a hardware issue like a power failure.

@Pedals2Paddles

This comment has been minimized.

Show comment
Hide comment
@Pedals2Paddles

Pedals2Paddles Oct 17, 2017

Contributor

Thanks for all the input on this during the dev call. And thanks @tridge for the help afterwards.

I've narrowed this down to two culprits:

  • Dataflash over mavlink alone is responsible for about 400 slow loops out of 4000.
  • Solo's mavlink gimbal alone is responsible for about 600 slow loops out of 4000.
  • Both enabled together (adds gimbal logging) are responsible for about 1200 slow loops out of 4000.
  • Both disabled, slow loops are 0 to 100 out of 4000 or only 2%.

The dataflash log bitmask is set for the default of 176126. Perhaps there is a better bitmask we can use that will reduce the overhead by eliminating unnecessary data? But I need some help coming up with a better one. I'd like to disable the gimbal logging for one thing, and maybe a few others that you guys think we can generally do without.

The gimbal, I'm not sure what to do about that?

Contributor

Pedals2Paddles commented Oct 17, 2017

Thanks for all the input on this during the dev call. And thanks @tridge for the help afterwards.

I've narrowed this down to two culprits:

  • Dataflash over mavlink alone is responsible for about 400 slow loops out of 4000.
  • Solo's mavlink gimbal alone is responsible for about 600 slow loops out of 4000.
  • Both enabled together (adds gimbal logging) are responsible for about 1200 slow loops out of 4000.
  • Both disabled, slow loops are 0 to 100 out of 4000 or only 2%.

The dataflash log bitmask is set for the default of 176126. Perhaps there is a better bitmask we can use that will reduce the overhead by eliminating unnecessary data? But I need some help coming up with a better one. I'd like to disable the gimbal logging for one thing, and maybe a few others that you guys think we can generally do without.

The gimbal, I'm not sure what to do about that?

@Pedals2Paddles

This comment has been minimized.

Show comment
Hide comment
@Pedals2Paddles

Pedals2Paddles Oct 17, 2017

Contributor

I did a little experiment this morning. I put a return; at the very beginning of this module (https://github.com/ArduPilot/ardupilot/blob/master/libraries/AP_Mount/SoloGimbal.cpp#L374) to effectively disable dataflash logging of the Solo's mavlink gimbal. This took slow loops from 1200 down to 800 (30% down to 20%).

So for one thing, I think a mount parameter is in order to enable/disable the GMB_ logging. That's a huge workload that doesn't serve any regular operational purpose.

That said, we're still way to high. So the logging bitmask is probably next best thing to attack.

Contributor

Pedals2Paddles commented Oct 17, 2017

I did a little experiment this morning. I put a return; at the very beginning of this module (https://github.com/ArduPilot/ardupilot/blob/master/libraries/AP_Mount/SoloGimbal.cpp#L374) to effectively disable dataflash logging of the Solo's mavlink gimbal. This took slow loops from 1200 down to 800 (30% down to 20%).

So for one thing, I think a mount parameter is in order to enable/disable the GMB_ logging. That's a huge workload that doesn't serve any regular operational purpose.

That said, we're still way to high. So the logging bitmask is probably next best thing to attack.

@amilcarlucas

This comment has been minimized.

Show comment
Hide comment
@amilcarlucas

amilcarlucas Oct 22, 2017

Contributor

Could this be the cause of crazy yaw issues when executing spline waypoints ? The so called "PH2.1 rodeo fight mode" ?
@Pedals2Paddles thanks for investigating this and doing some progress, I will try to add the return; and set logging mask to 0 in order to see if it helps

Contributor

amilcarlucas commented Oct 22, 2017

Could this be the cause of crazy yaw issues when executing spline waypoints ? The so called "PH2.1 rodeo fight mode" ?
@Pedals2Paddles thanks for investigating this and doing some progress, I will try to add the return; and set logging mask to 0 in order to see if it helps

@Pedals2Paddles

This comment has been minimized.

Show comment
Hide comment
@Pedals2Paddles

Pedals2Paddles Oct 23, 2017

Contributor

@amilcarlucas I doubt it is causing that. Isn't that an issue with how waypoints are approached that has been the subject of a lot of discussion recently? Nothing solo specific that I'm aware of. That's something everyone has been griping about I think?

Contributor

Pedals2Paddles commented Oct 23, 2017

@amilcarlucas I doubt it is causing that. Isn't that an issue with how waypoints are approached that has been the subject of a lot of discussion recently? Nothing solo specific that I'm aware of. That's something everyone has been griping about I think?

@OXINARF OXINARF removed the DevCallTopic label Nov 6, 2017

@rob215x

This comment has been minimized.

Show comment
Hide comment
@rob215x

rob215x Nov 8, 2017

This is happening on ships other than SOLO. I'm experiencing it with a scratch built quad running Pixhawk2 and Copter 3.5.3. Here's my latest log if that helps:
https://www.dropbox.com/s/1mw9c0je4sjs7mp/2017-11-07%2016-47-01.bin?dl=0

rob215x commented Nov 8, 2017

This is happening on ships other than SOLO. I'm experiencing it with a scratch built quad running Pixhawk2 and Copter 3.5.3. Here's my latest log if that helps:
https://www.dropbox.com/s/1mw9c0je4sjs7mp/2017-11-07%2016-47-01.bin?dl=0

@rmackay9

This comment has been minimized.

Show comment
Hide comment
@rmackay9

rmackay9 Nov 8, 2017

Contributor

@rob215x, so your log shows about 350 slow loops out of 4000 (9%). much lower than what the Solo is showing. If it's not causing problems then I wouldn't worry about it too much. If you want to dig into it then it's really about trying to turn stuff off. So reducing the LOG_BITMASK would be one thing to try. Reducing mavlink output by reducing SRx_ parameter values. In Copter-3.5.4 you'll be able to disable compass drivers completely using the COMPASS_TYPEMASK.

So these are a few things to try. My guess is that although it's disconcerting to see the number in the logs, it's not really causing flight issues. Still.. some advice above until we look into it further.

Contributor

rmackay9 commented Nov 8, 2017

@rob215x, so your log shows about 350 slow loops out of 4000 (9%). much lower than what the Solo is showing. If it's not causing problems then I wouldn't worry about it too much. If you want to dig into it then it's really about trying to turn stuff off. So reducing the LOG_BITMASK would be one thing to try. Reducing mavlink output by reducing SRx_ parameter values. In Copter-3.5.4 you'll be able to disable compass drivers completely using the COMPASS_TYPEMASK.

So these are a few things to try. My guess is that although it's disconcerting to see the number in the logs, it's not really causing flight issues. Still.. some advice above until we look into it further.

@amilcarlucas

This comment has been minimized.

Show comment
Hide comment
@amilcarlucas

amilcarlucas Mar 9, 2018

Contributor

@Pedals2Paddles Can you post a link to the discussions on "how waypoints are approached" ?

Contributor

amilcarlucas commented Mar 9, 2018

@Pedals2Paddles Can you post a link to the discussions on "how waypoints are approached" ?

@Pedals2Paddles

This comment has been minimized.

Show comment
Hide comment
@Pedals2Paddles

Pedals2Paddles Mar 10, 2018

Contributor

Not sure what discussion you mean?

Contributor

Pedals2Paddles commented Mar 10, 2018

Not sure what discussion you mean?

@amilcarlucas

This comment has been minimized.

Show comment
Hide comment
@amilcarlucas

amilcarlucas Mar 13, 2018

Contributor

I am referring to your comment from 23 Oct 2017 #7060 (comment)

Contributor

amilcarlucas commented Mar 13, 2018

I am referring to your comment from 23 Oct 2017 #7060 (comment)

@Pedals2Paddles

This comment has been minimized.

Show comment
Hide comment
@Pedals2Paddles

Pedals2Paddles Aug 4, 2018

Contributor

Closing this as there isn't a bug or problem. It's just a resource hog, which is mitigated by ChibiOS.

Contributor

Pedals2Paddles commented Aug 4, 2018

Closing this as there isn't a bug or problem. It's just a resource hog, which is mitigated by ChibiOS.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment