Timing of InteractionLoop

Asked by Jan Stránský

Hello,
I used timing module and got following results. The interactionLoop is there measured as a whole. Is there an easy way how to measure the time spent on Ig2, Ip2 and Law 2 parts separately?
Thanks
Jan

Name Count Time Rel. time
-------------------------------------------------------------------------------------------------------
ForceResetter 13192 15916510us 0.25%
"collider" 10778 630760630us 9.77%
InteractionLoop 13192 5482474050us 84.91%
"driver" 13192 1214830us 0.02%
"newton" 13192 297679993us 4.61%
CpmStateUpdater 11 2503597us 0.04%
PyRunner 10 25598588us 0.40%
PyRunner 10 894295us 0.01%
PyRunner 13 6400us 0.00%
PyRunner 131 16580us 0.00%
"plotDataCollector" 100 40232us 0.00%
TOTAL 6457105712us 100.00%

Question information

Language:
English Edit question
Status:
Solved
For:
Yade Edit question
Assignee:
No assignee Edit question
Solved by:
Bruno Chareyre
Solved:
Last query:
Last reply:
Revision history for this message
Best Bruno Chareyre (bruno-chareyre) said :
#1

I don't see any way without touching the code.
There are IDISP_TIMING and IDISP_CHECKPOINT flags, but they do nothing
apparently.

You could use them and include some timingDeltas->checkpoint ( "..." )
at appropriate lines. It will probably not work in multithread.

Revision history for this message
Jan Stránský (honzik) said :
#2

finally I did it in this way :-)
thanks
Jan

Revision history for this message
Jan Stránský (honzik) said :
#3

Thanks Bruno Chareyre, that solved my question.

Revision history for this message
Bruno Chareyre (bruno-chareyre) said :
#4

I was wondering if timingDeltas could measure accurately such very small operations.
How do the results look like?

Revision history for this message
Jan Stránský (honzik) said :
#5

The timingDeltas can measure small operations, but if they are paced inside
Law2... functor, they are called huge amount of times, so mere timing
measurement takes unnegligable time. From one specific example, with
detailed timing the InteractionLoop took cca 9.3M usec, without 1.8M
usec... So it is discutable if the measurement is really representative..
Jan

2013/4/24 Bruno Chareyre <email address hidden>

> Question #227049 on Yade changed:
> https://answers.launchpad.net/yade/+question/227049
>
> Bruno Chareyre posted a new comment:
> I was wondering if timingDeltas could measure accurately such very small
> operations.
> How do the results look like?
>
> --
> You received this question notification because you are a member of
> yade-users, which is an answer contact for Yade.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~yade-users
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~yade-users
> More help : https://help.launchpad.net/ListHelp
>

Revision history for this message
Bruno Chareyre (bruno-chareyre) said :
#6

It is a huge but expected increase. It could be ok. If you sum the subtimings of the ILoop, does it give 1.8 or 9.3?...

Revision history for this message
Jan Stránský (honzik) said :
#7

If I sum all the functors, it gives approx 60% (16.31 + 0.01 + 0.18 + 45.44
:-) If I sum timingDeltas within one functor, it gives expected 100%, see
example below
Jan

Name Count
  Time Rel. time
-------------------------------------------------------------------------------------------------------
ForceResetter 102
2315us 0.02%
"collider" 5
 60720us 0.58%
InteractionLoop 102
10241332us 98.23%
  Ig2_Sphere_Sphere_ScGeom 1222186
 1670358us 16.31%
    Ig2_Sphere_Sphere_ScGeom 1222186
 1670358us 100.00%
  Ig2_Facet_Sphere_ScGeom 753
1050us 0.01%
    Ig2_Facet_Sphere_ScGeom 753
1050us 100.00%
  Ip2_CpmMat_CpmMat_CpmPhys 11712
 18167us 0.18%
    end of Ip2_CpmPhys 11712
 18167us 100.00%
  Ip2_FrictMat_CpmMat_FrictPhys 0
 0us 0.00%
  Law2_ScGeom_CpmPhys_Cpm 3583872
 4653583us 45.44%
    GO A 1194624
 1375304us 29.55%
    GO B 1194624
 1764549us 37.92%
    rest 1194624
 1513729us 32.53%
    TOTAL 3583872
 4653583us 100.00%
  Law2_ScGeom_FrictPhys_CundallStrack 0
 0us 0.00%
"combEngine" 102
8936us 0.09%
"newton" 102
 74573us 0.72%
"cpmStateUpdater" 1
 20204us 0.19%
PyRunner 0
 0us 0.00%
PyRunner 0
 0us 0.00%
PyRunner 0
 0us 0.00%
PyRunner 0
 0us 0.00%
PyRunner 1
 135us 0.00%
"plotDataCollector" 1
 16281us 0.16%
"timingstats" 1
1343us 0.01%
PyRunner 0
 0us 0.00%
TOTAL

2013/4/25 Bruno Chareyre <email address hidden>

> Question #227049 on Yade changed:
> https://answers.launchpad.net/yade/+question/227049
>
> Bruno Chareyre posted a new comment:
> It is a huge but expected increase. It could be ok. If you sum the
> subtimings of the ILoop, does it give 1.8 or 9.3?...
>
> --
> You received this question notification because you are a member of
> yade-users, which is an answer contact for Yade.
>
> _______________________________________________
> Mailing list: https://launchpad.net/~yade-users
> Post to : <email address hidden>
> Unsubscribe : https://launchpad.net/~yade-users
> More help : https://help.launchpad.net/ListHelp
>