Instance-Based Call Tracing

The openmdao trace command can be used to print a trace of each instance method call. For example:

openmdao trace <your_python_script_here>

Whenever a method is called that matches the search criteria, the following will be written to the console, indented based on its location in the call stack. :

  1. Pathname of the object instance (if available)

  2. Class

  3. Instance ID

  4. Method name

For example:

 Problem#1.Problem.__init__
     Group#1.Group.__init__
         Group#1.System.__init__
             DictionaryJacobian#1.Jacobian.__init__
             Group#1().System.initialize
         NonlinearRunOnce#1.Solver.__init__
             NonlinearRunOnce#1.Solver._declare_options
         LinearRunOnce#1.LinearSolver.__init__
             LinearRunOnce#1.Solver.__init__
                 LinearRunOnce#1.Solver._declare_options
     Driver#1.Driver.__init__
 IndepVarComp#1.IndepVarComp.__init__
     IndepVarComp#1.ExplicitComponent.__init__
         IndepVarComp#1.Component.__init__
             IndepVarComp#1.System.__init__
                 DictionaryJacobian#2.Jacobian.__init__
                 IndepVarComp#1().System.initialize
 Propulsor#1.Group.__init__
     Propulsor#1.System.__init__
         DictionaryJacobian#3.Jacobian.__init__
         Propulsor#1().System.initialize
     NonlinearRunOnce#2.Solver.__init__
         NonlinearRunOnce#2.Solver._declare_options
     LinearRunOnce#2.LinearSolver.__init__
         LinearRunOnce#2.Solver.__init__
             LinearRunOnce#2.Solver._declare_options
 Problem#1.Problem.set_solver_print
     Group#1().System.set_solver_print
         LinearRunOnce#2.Solver._set_solver_print
         NonlinearRunOnce#2.Solver._set_solver_print
 Problem#1.Problem.setup
     Group#1().System._setup
         Group#1().System._get_initial_procs
         Group#1().Group._setup_procs
             IndepVarComp#1().System._setup_procs
             Propulsor#1().Group._setup_procs
                 FlightConditions#1.Group.__init__
                     FlightConditions#1.System.__init__
                         DictionaryJacobian#4.Jacobian.__init__
                         FlightConditions#1().FlightConditions.initialize
                     NonlinearRunOnce#3.Solver.__init__
                         NonlinearRunOnce#3.Solver._declare_options
                     LinearRunOnce#3.LinearSolver.__init__
                         LinearRunOnce#3.Solver.__init__
                             LinearRunOnce#3.Solver._declare_options

...

Note that we must always include the class name and instance ID, even when the instance has a pathname attribute, because there are times early in execution where either the pathname attribute doesn’t exist yet, as in the beginning of __init__ method, or pathname exists but still has the default value of “” instead of its eventual value, as in the _setup_procs method.

For more verbose output, which includes values of function locals and return values, as well as the number of times a function has been called, use the -v arg. For example:

openmdao trace -v <your_python_script_here>

Which will result in output that looks like this:

Problem#1.Problem.__init__ (1)
  comm=None
  model=None
  root=None
  self=<openmdao.core.problem.Problem object>
    Group#1.Group.__init__ (1)
      kwargs={}
      self=<openmdao.core.group.Group object>
        Group#1.System.__init__ (1)
          kwargs={}
          self=<openmdao.core.group.Group object>
            DictionaryJacobian#1.Jacobian.__init__ (1)
              kwargs={}
              self=<openmdao.jacobians.dictionary_jacobian.DictionaryJacobian object>
            <-- DictionaryJacobian#1.Jacobian.__init__
            Group#1().System.initialize (1)
              self=<openmdao.core.group.Group object>
            <-- Group#1().System.initialize
        <-- Group#1().System.__init__
        NonlinearRunOnce#1.Solver.__init__ (1)
          kwargs={}
          self=NL: RUNONCE
            NonlinearRunOnce#1.Solver._declare_options (1)
              self=NL: RUNONCE
            <-- NonlinearRunOnce#1.Solver._declare_options
        <-- NonlinearRunOnce#1.Solver.__init__
        LinearRunOnce#1.LinearSolver.__init__ (1)
          kwargs={}
          self=LN: RUNONCE
            LinearRunOnce#1.Solver.__init__ (1)
              kwargs={}
              self=LN: RUNONCE
                LinearRunOnce#1.Solver._declare_options (1)
                  self=LN: RUNONCE
                <-- LinearRunOnce#1.Solver._declare_options
            <-- LinearRunOnce#1.Solver.__init__
        <-- LinearRunOnce#1.LinearSolver.__init__
    <-- Group#1().Group.__init__
    Driver#1.Driver.__init__ (1)
      self=<openmdao.core.driver.Driver object>
    <-- Driver#1.Driver.__init__
<-- Problem#1.Problem.__init__

...

By default, a pre-defined set of general OpenMDAO functions will be included in the trace, but that can be changed using the -g option. For example, in order to trace only setup-related functions, do the following:

openmdao trace -v <your_python_script_here> -g setup

The tracer can also display the change in memory usage from the time a function is called to the time it returns. To show memory usage, use the -m option, for example:

openmdao trace -m <your_python_script_here>

will result in output like this:

...

Group#1().Group._setup_procs
    DistribOuptutImplicit#0().System._setup_procs
        PETScKrylov#0.PETScKrylov.__init__
            PETScKrylov#0.LinearSolver.__init__
                PETScKrylov#0.Solver.__init__
                    PETScKrylov#0.PETScKrylov._declare_options
                    <-- PETScKrylov#0.PETScKrylov._declare_options (time:  0.06384) (total: 75.445 MB)
                <-- PETScKrylov#0.Solver.__init__ (time:  0.06391) (total: 75.445 MB)
            <-- PETScKrylov#0.LinearSolver.__init__ (time:  0.06397) (total: 75.445 MB)
        <-- PETScKrylov#0.PETScKrylov.__init__ (time:  0.06402) (total: 75.445 MB)
    <-- DistribOuptutImplicit#0(aero.icomp).System._setup_procs (time:  0.06519) (total: 77.371 MB) (diff: +4772 KB)
    DistribInputExplicit#0().System._setup_procs
    <-- DistribInputExplicit#0(aero.ecomp).System._setup_procs (time:  0.06738) (total: 79.281 MB) (diff: +1956 KB)
<-- Group#1(aero).Group._setup_procs (time:  0.06746) (total: 79.281 MB)

...

Note that total memory usage and elapsed time is shown on each function return line. Those function returns where a difference in memory was found will display the difference at the end of the line.

The tracer can also be used to help track down memory leaks. Using the -l option, it will display a list of object types and their counts that were created since the function was called and not garbage collected after the function returned. For example:

openmdao trace -l <your_python_script_here> -g solver

will result in output like this:

...

LinearRunOnce#0.LinearRunOnce.solve
    LinearRunOnce#0.LinearBlockGS._iter_execute
        LinearRunOnce#1.LinearRunOnce.solve
            LinearRunOnce#1.LinearBlockGS._iter_execute
                PETScKrylov#0.PETScKrylov.solve
                <-- PETScKrylov#0.PETScKrylov.solve
            <-- LinearRunOnce#1.LinearBlockGS._iter_execute
        <-- LinearRunOnce#1.LinearRunOnce.solve
           Recording +1
    <-- LinearRunOnce#0.LinearBlockGS._iter_execute
<-- LinearRunOnce#0.LinearRunOnce.solve
   Recording +1

...

This output shows that in LinearRunOnce#1.LinearRunOnce.solve, a Recording object was created and not garbage collected. Note that this does not always indicate a memory leak, as there are some functions that intentionally create new objects that are intended to last beyond the life of the function. This tool merely gives you a place to look in the code where a memory leak might exist.

To see a list of the available pre-defined sets of functions to trace, look at the usage info for the -g command that can be obtained as follows:

openmdao trace -h
usage: openmdao trace [-h] [-g METHODS] [-v] [--ptrs] [-m] [-l] [-r RANK]
                      [-o OUTFILE] [-f FILTERS]
                      file

positional arguments:
  file                  Python file to be traced.

optional arguments:
  -h, --help            show this help message and exit
  -g METHODS, --group METHODS
                        Determines which group of methods will be traced.
                        Default is "openmdao". Options are: ['coloring',
                        'dataflow', 'driver', 'jac', 'linear', 'mpi',
                        'openmdao', 'openmdao_all', 'setup', 'solver',
                        'transfer']
  -v, --verbose         Show function locals and return values.
  --ptrs                Show addresses of printed objects.
  -m, --memory          Show memory usage.
  -l, --leaks           Show objects that are not garbage collected after each
                        function call.
  -r RANK, --rank RANK  MPI rank where output is desired. Default is all
                        ranks.
  -o OUTFILE, --outfile OUTFILE
                        Output file. Defaults to stdout.
  -f FILTERS, --filter FILTERS
                        An expression. If it evaluates to True for any
                        matching trace function, that function will be
                        displayed in the trace. One expression can be added
                        for each class.