[petsc-users] PetscLogEvent

[Matthew Knepley]

On Wed, Jan 5, 2011 at 8:43 PM, Gu Shiyuan <gshy2014 at gmail.com> wrote:

> Hi all,
>     I make up a learning examples but cannot explain the result:
>     In the following codes, everything inside the stage[1] is between
> PetscLogEventBegin() and PetscLogEventEnd(), so I expect the time of the
> EVENT_MGSolver should take up 100% percent of the time in this stage. But
> log_summary only gives me 97%. Where is the 3%?
>

I would need to see the code to answer completely, however things happen
from the program launch until
your EventBegin() and from your EventEnd() until termination.


>
>     PetscLogStagePush(stages[1]);
>     PetscLogEventBegin(MGSolver,0,0,0,0);
>        for(l=0;l<100;l++){
>            ///// some functions calls
>      }
>      PetscLogEventEnd(MGSolver,0,0,0,0);
>      PetscLogStagePop();
>
> -log_summary:
> --- Event Stage 2:
>
> MatMult           241600 1.0 3.4837e+01 1.0 1.06e+10 1.0 0.0e+00 0.0e+00
> 0.0e+00 64 75  0  0  0  65 75  0  0  0   303
> MatMultAdd         53200 1.0 2.9537e+00 1.0 6.91e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  5  5  0  0  0   6  5  0  0  0   234
> MatSolve           35200 1.0 6.0787e-02 1.0 3.01e+06 1.0 0.0e+00 0.0e+00
> 0.0e+00  0  0  0  0  0   0  0  0  0  0    50
> VecDot            272000 1.0 1.6983e+00 1.0 7.64e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  3  5  0  0  0   3  5  0  0  0   450
> VecNorm            35200 1.0 4.8882e-02 1.0 5.28e+05 1.0 0.0e+00 0.0e+00
> 0.0e+00  0  0  0  0  0   0  0  0  0  0    11
> VecScale          117600 1.0 6.2790e-01 1.0 2.62e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  1  2  0  0  0   1  2  0  0  0   417
> VecCopy           141600 1.0 1.4639e+00 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> 0.0e+00  3  0  0  0  0   3  0  0  0  0     0
> VecSet             35200 1.0 3.4475e-02 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> 0.0e+00  0  0  0  0  0   0  0  0  0  0     0
> VecAXPY            35200 1.0 3.4980e-02 1.0 5.63e+05 1.0 0.0e+00 0.0e+00
> 0.0e+00  0  0  0  0  0   0  0  0  0  0    16
> VecAYPX           288400 1.0 3.4488e+00 1.0 8.93e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  6  6  0  0  0   6  6  0  0  0   259
> VecWAXPY          100800 1.0 1.3907e+00 1.0 3.81e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  3  3  0  0  0   3  3  0  0  0   274
> VecPointwiseMult  320000 1.0 4.8273e+00 1.0 5.72e+08 1.0 0.0e+00 0.0e+00
> 0.0e+00  9  4  0  0  0   9  4  0  0  0   119
> KSPSolve           17600 1.0 5.6411e-01 1.0 6.14e+06 1.0 0.0e+00 0.0e+00
> 0.0e+00  1  0  0  0  0   1  0  0  0  0    11
> PCApply            35200 1.0 1.2111e-01 1.0 3.01e+06 1.0 0.0e+00 0.0e+00
> 0.0e+00  0  0  0  0  0   0  0  0  0  0    25
> MGSolver               1 1.0 5.3215e+01 1.0 1.41e+10 1.0 0.0e+00 0.0e+00
> 0.0e+00 97100  0  0  0 100100  0  0  0   265
>
> -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> Moreover,
> What are the last four parameters of  PetscLogEventBegin() used for? The
> manually vaguely states that "objects associated with the event".
> The provided examples set them to zeros. In what situation should we pass a
> non-zero?
>

Never, they were there for an old visualization tool.


>  I can obtain profiling information with -log_summary but I get nothing
> with -log or -log_all. Did I miss any steps for -log/-log_all to work?
>

Those are for tracing.

  Thanks,

     Matt


> Thanks.
>
>
>



-- 
What most experimenters take for granted before they begin their experiments
is infinitely more interesting than any results to which their experiments
lead.
-- Norbert Wiener
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mcs.anl.gov/pipermail/petsc-users/attachments/20110105/01d75b1b/attachment.htm>