profiling PETSc code
Matt Funk
mafunk at nmsu.edu
Tue Aug 1 18:49:46 CDT 2006
Hi,
i don't think it is the mallocs since it says things like:
[0] MatAssemblyEnd_SeqAIJMatrix size: 2912 X 2912; storage space: 0
unneeded,2912 used
[0] MatAssemblyEnd_SeqAIJNumber of mallocs during MatSetValues() is 0
However, i do get errors. They look like:
[0]PETSC ERROR: StageLogRegister() line 95 in src/sys/plog/stageLog.c
[0]PETSC ERROR: Invalid pointer!
[0]PETSC ERROR: Null Pointer: Parameter # 3!
[0]PETSC ERROR: PetscLogStageRegister() line 375 in src/sys/plog/plog.c
which happens during the call PETSCInitialize(...);
After that i get an error like:
[0] PetscCommDuplicateDuplicating a communicator 91 164 max tags = 1073741823
[0] PetscCommDuplicateUsing internal PETSc communicator 91 164
[0] PetscCommDuplicateUsing internal PETSc communicator 91 164
[0] PetscCommDuplicateUsing internal PETSc communicator 91 164
[0]PETSC ERROR: MatGetVecs() line 6283 in src/mat/interface/matrix.c
[0]PETSC ERROR: Null argument, when expecting valid pointer!
[0]PETSC ERROR: Null Object: Parameter # 1!
[0]PETSC ERROR: KSPGetVecs() line 555 in src/ksp/ksp/interface/iterativ.c
[0]PETSC ERROR: KSPDefaultGetWork() line 597 in
src/ksp/ksp/interface/iterativ.c
[0]PETSC ERROR: KSPSetUp_CG() line 75 in src/ksp/ksp/impls/cg/cg.c
[0]PETSC ERROR: KSPSetUp() line 198 in src/ksp/ksp/interface/itfunc.c
so i suppose that is a problem. I am just not sure what it means.
any ideas?
mat
On Tuesday 01 August 2006 16:36, Matthew Knepley wrote:
> On 8/1/06, Matt Funk <mafunk at nmsu.edu> wrote:
> > Hi,
> >
> > well, now i do get summary:
> > ...
> > # WARNING!!! #
> > # #
> > # This code was run without the PreLoadBegin() #
> > # macros. To get timing results we always recommend #
> > # preloading. otherwise timing numbers may be #
> > # meaningless. #
> > ##########################################################
> >
> >
> > Event Count Time (sec) Flops/sec
> > --- Global --- --- Stage --- Total
> > Max Ratio Max Ratio Max Ratio Mess Avg len
> > Reduct %T %F %M %L %R %T %F %M %L %R Mflop/s
> > -------------------------------------------------------------------------
> >-----------------------------------------------
> >
> > --- Event Stage 0: Main Stage
> >
> > VecNorm 200 1.0 5.6217e-03 1.0 2.07e+08 1.0 0.0e+00 0.0e+00
> > 1.0e+02 0 36 0 0 7 0 36 0 0 31 207
> > VecCopy 200 1.0 4.2303e-03 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
> > VecSet 1 1.0 8.1062e-06 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
> > VecAYPX 100 1.0 3.2036e-03 1.0 1.82e+08 1.0 0.0e+00 0.0e+00
> > 0.0e+00 0 18 0 0 0 0 18 0 0 0 182
> > MatMult 100 1.0 8.3530e-03 1.0 3.49e+07 1.0 0.0e+00 0.0e+00
> > 0.0e+00 1 9 0 0 0 1 9 0 0 0 35
> > MatSolve 200 1.0 2.5591e-02 1.0 2.28e+07 1.0 0.0e+00 0.0e+00
> > 0.0e+00 2 18 0 0 0 2 18 0 0 0 23
> > MatSolveTranspos 100 1.0 2.1357e-02 1.0 1.36e+07 1.0 0.0e+00 0.0e+00
> > 0.0e+00 2 9 0 0 0 2 9 0 0 0 14
> > MatLUFactorNum 100 1.0 4.6215e-02 1.0 6.30e+06 1.0 0.0e+00 0.0e+00
> > 0.0e+00 3 9 0 0 0 3 9 0 0 0 6
> > MatILUFactorSym 1 1.0 4.4894e-04 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> > 2.0e+00 0 0 0 0 0 0 0 0 0 1 0
> > MatAssemblyBegin 1 1.0 2.1458e-06 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
> > MatAssemblyEnd 100 1.0 1.1220e-02 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> > 0.0e+00 1 0 0 0 0 1 0 0 0 0 0
> > MatGetOrdering 1 1.0 2.5296e-04 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> > 2.0e+00 0 0 0 0 0 0 0 0 0 1 0
> > KSPSetup 100 1.0 5.3692e-04 1.0 0.00e+00 0.0 0.0e+00 0.0e+00
> > 1.4e+01 0 0 0 0 1 0 0 0 0 4 0
> > KSPSolve 100 1.0 9.0056e-02 1.0 3.23e+07 1.0 0.0e+00 0.0e+00
> > 3.0e+02 7 91 0 0 21 7 91 0 0 93 32
> > PCSetUp 100 1.0 4.9087e-02 1.0 5.93e+06 1.0 0.0e+00 0.0e+00
> > 4.0e+00 4 9 0 0 0 4 9 0 0 1 6
> > PCApply 300 1.0 4.9106e-02 1.0 1.78e+07 1.0 0.0e+00 0.0e+00
> > 0.0e+00 4 27 0 0 0 4 27 0 0 0 18
> > -------------------------------------------------------------------------
> >-----------------------------------------------
> >
> > Memory usage is given in bytes:
> >
> > Object Type Creations Destructions Memory Descendants' Mem.
> >
> > --- Event Stage 0: Main Stage
> >
> > Index Set 3 3 35976 0
> > Vec 109 109 2458360 0
> > Matrix 2 2 23304 0
> > Krylov Solver 1 1 0 0
> > Preconditioner 1 1 168 0
> > =========================================================================
> >=============================================== Average time to get
> > PetscTime(): 9.53674e-08
> > Compiled without FORTRAN kernels
> > Compiled with full precision matrices (default)
> >
> > ...
> >
> > am i using the push and pop calls in an manner they are not intended to
> > be used?
>
> Not exactly. You need to register a stage first before pushing it.
>
>
> http://www-unix.mcs.anl.gov/petsc/petsc-as/snapshots/petsc-current/docs/man
>ualpages/Profiling/PetscLogStageRegister.html
>
> > plus, how can i see what's going on with respect to why it takes so much
> > longer to solve the system in parallel than in serial without being able
> > to specify the stages (i.e single out the KSPSolve call)?
>
> There are 100 calls to KSPSolve() which collectively take .1s. Your
> problem is most
> likely in matrix setup. I would bet that you have not preallocated the
> space correctly.
> Therefore, a malloc() is called every time you insert a value. You can
> check the number of mallocs using -info.
>
> Matt
>
> > mat
> >
> > On Tuesday 01 August 2006 15:57, Matthew Knepley wrote:
> > > ke out your stage push/pop for the moment, and the log_summary
> > > call. Just run with -log_summary and send the output as a test.
> > >
> > > Thanks,
> > >
> > > Matt
More information about the petsc-users
mailing list