How can I get the timing info of Chrono

[Jiapeng Liu]

Hi Radu,

I am running the demo_MBS_collision_trimesh.cpp demo. 

I wanna get the timing info spent in broad and narrow collision process especially when I run the code in multiple threads.

Currently, I am using sys.GetTimerCollisionBroad() and sys.GetTimerCollisionNarrow() to get the corresponding timing info. Is it the correct way?

Plus, I find Chrono has different ways to profile the code.

1. ChTimer timer_step/ timer_advance/ timer_ls_solve;   

2. CH_PROFILE("ComputeCollisions");

3. BT_PROFILE("performDiscreteCollisionDetection");

Could you please elaborate what are the differences among these three methods? Which one should I use for multi-thread timing?

Thank you for your help in advance!

Best

Jiapeng

[Radu Serban]

Hi Jiapeng,

 

Yes, using sys.GetTimerCollisionBroad() and sys.GetTimerCollisionNarrow() is probably what you need.  A few more explanations below, for completeness.

 

The BT_PROFILE is the Bullet internal profiling mechanism.  You could use that as well, but then you’ll have to consult their documentation or else look in the code to understand which phases are timed and profiled exactly.

 

CH_PROFILE is a similar mechanism for a Chrono simulation (in fact, you will see that the CH_PROFILE mimics the one in Bullet).  CH_PROFILE produces a profile hierarchy which includes measurements for the overall collision detection, as well as the separate “children” timing measurements of the broad and narrow phases (although the latter are currently only included for the Bullet collision system and not yet for the Multicore collision detection system – I’ll look into making this consistent at some point in the future).

 

In addition, we keep various timer objects (of type ChTimer) which are used to measure the time spent in various phases of the Chrono solution.  There are timers managed by and available from ChSystem for the main solution stages (overall step, advance, linear solver setup, linear solver solution, etc).  Those include a timer for the collision detection phase (over the last step); in addition, you can access collision system implementation-specific timers to get the breakdown for the broadphase and narrowphase timings (the two functions you already mentioned).

 

The timing information provided by CH_PROFILE and by the various ChTimer objects will be consistent (and, for the collision detection timers, so should be CH_PROFILE and BT_PROFILE).  You can see this for the Bullet code:

 

{

  BT_PROFILE("computeOverlappingPairs");         ß broadphase timing for BT_PROFILE (measures time in current block)

  CH_PROFILE("Broad-phase");                     ß broadphase timing for CH_PROFILE (measures time in current block)

  timer_collision_broad.start();                 --

  computeOverlappingPairs();                       |à broadphase ChTimer (measures time between start and stop)

  timer_collision_broad.stop();                  --

}

 

cbtDispatcher* dispatcher = getDispatcher();

 

{

  BT_PROFILE("dispatchAllCollisionPairs");       ß narrowphase timing for BT_PROFILE

  CH_PROFILE("Narrow-phase");                    ß narrowphase timing for CH_PROFILE

  timer_collision_narrow.start();                --

  if (dispatcher)                                  |à narrowphase ChTimer

    dispatcher->dispatchAllCollisionPairs(...);    |

  timer_collision_narrow.stop();                 --

}

 

Hope that this helps,
--Radu

--
You received this message because you are subscribed to the Google Groups "ProjectChrono" group.
To unsubscribe from this group and stop receiving emails from it, send an email to projectchron...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/projectchrono/f6437742-297e-4b4f-973b-32320499761dn%40googlegroups.com.

[Jiapeng Liu]

Hi Radu,

Thank you so much for so detailed explanation. 

1. Currently, I am using sys.GetTimerCollisionBroad() and sys.GetTimerCollisionNarrow() to get the timing info of the Broad/Narrow Collision process. However, the results look weird to me.

Here are the results:

What I find is the average total/Broad/Narrow Collision (Total time/number of timesteps) looks weird with the number of threads increasing.

1.1 With the number of threads increasing from 1 to 2, the ave. time increases, which doesn't make sense to me.

1.2 With the number of threads increasing from 2 to 4, the ave. time decrease, which makes sense to me.

1.3 Additionally, the ave. time of 4-threads simulation is still larger than that of single-thread simulation, which doesn't make sense to me.

1.4 I don't know if the timer result is correct especially for multi-threaded process. I don't know exactly what the timing results means for multi-threaded process. Is it the total wall time, or total CPU time(multiple threads are used)?

I put more results in the slides and attach them in this conversation. Please check them for more details.

I also attach the model file (*.cpp and *.stl) in this conversation. Notice that my model is based on demo_MBS_collision_trimesh.cpp.

2. I will try to use CH_PROFILE to get the timing info for the same simulation and compare results with the previous ones obtained through sys.GetTimerCollisionBroad() and sys.GetTimerCollisionNarrow().

Do you know how to use CH_PROFILE to get the timing info? Is there an example?

I greatly appreciate your time and help for what you have done for me. 

Best

Jiapeng

[Jiapeng Liu]