Profiling: What does "traversal.py:60(traverse_terminals)" do?

Question

I'm profiling my code with cProfile and get the following as the top time-consumers:

   Ordered by: internal time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    18539   48.115    0.003   48.115    0.003 {_fem.Assembler_assemble}
     2432   20.644    0.008  109.537    0.045 {_la.PETScSNESSolver_solve}
  4333032   10.842    0.000   18.535    0.000 traversal.py:60(traverse_terminals)
      942    5.902    0.006    5.907    0.006 20c_failsafe_with_barrier.py:287(toFile)
 14036571    5.032    0.000    5.033    0.000 {isinstance}
     2432    2.533    0.001    2.533    0.001 {_la.PETScKrylovSolver_solve}

I understand most of it except the 'traversal.py' call. Line 60 is inside a class definition which, as I understand not optimal, is only called once so I wouldn't expect SO time consuming...

class LowerBound(Expression):
def eval(self, values, x):
    values[0] = 0.00001
    values[1] = -100.
def value_shape(self):
    return (2,)

Can anyone enlighten me?

Answer 1

You probably have UFL code inside your loop. Every time it is hit, UFL has to process the code to figure out what it is, and DOLFIN/Instant need to check if it's been compiled. Move your UFL code outside of any loops.