Tinkering with Time

Nothing to do with Dr Who’s 50th anniversary episode (though it was good, wasn’t it!).

For a while I’ve been interested in doing some performance profiling on Phoebe’s code, and had got lots of good advice from the Raspberry Pi forum.

So while I was waiting for the glue to dry on her reconstructed frame last night, I knocked some very simple profiling code into Phoebe’s main loop and it threw out these figures.

loop speed 110.699372 loops per second
% fsm: 24.976521
% sensors: 50.086001
% eangles: 2.017404
% iangles: 0.420382
% angles_filter: 0.626013
% sensor_angles: 0.980850
% speed_pids: 5.348638
% angle_pids: 5.303506
% pid_outputs: 10.328892

The fact the FSM code took 25% of the time amazed me as it’s only simple – however a quick dig shows it also includes the main logging – rather than logging once per loop, logging every 0.1s reduced the FSM percentage significantly.

The next point of interest is the 50% reading the sensors.  It set a train of thought rolling

  • 100 loops per second = 10ms period per loop
  • 50% of each loop is reading the sensors = 5ms per loop dedicated to reading the sensors
  • The MPU6050 is currently configured to update the output registers 200 times a second – therefore each batch of data will be there for 5ms
  • which makes me wonder whether that sample rate is fast enough or will we get data misses sometimes?

Some code tinkering showed it could be improved by upping the sampling speed to 250Hz in the MPU6050 configuration.  I tried 333Hz also, but that was then updating samples faster than they could be read leading to errors, and reducing performance.

Now there’s not much point going beyond 250Hz – the PWM can only be updated @ 300Hz anyway (an RPIO PWM limit), but still, I’m pleased; this opens up a lot more time in the code that I can use for listening on a TCP socket for RC commands.

So here’s the improved figures:

loop speed 164.855286 loops per second
fsm: 4.010887
sensors: 58.669735
eangles: 2.894867
iangles: 0.672797
angles_filter: 1.054403
sensor_angles: 1.599324
speed_pids: 7.927051
angle_pids: 7.947845
pid_outputs: 15.304528

Three points:

  • the overall loop speed is up to 165 per second or 0.00606ms per loop
  • the FSM time is now down to 0.25 ms per cycle compared to the previous 2.25ms – nearly a factor of 10 improvement
  • the sensor read time is down to 3.6ms from 4.5ms

There may be further improvements in sensor reading to be made by making it interrupt driven running in another thread waking the main thread up only when there is new data – I might have a play with that, but for the moment, this is good enough.

Actually combined with the changes I made previously, I’m pretty chuffed at this improvement – from 50 loops per second to 165 while actually adding new code / function!

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.