2

I have some existing code that I'm trying to profile. I can successfully line profile class methods by adding a @profile decorator using kernprof.

Is there a general way to profile class instantiation? I have a few classes that have a quite complex inheritance structure. When I try to profile their init functions I get something like this:

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   179                                               def __init__(self, data):
   180         1    8910739.0 8910739.0    100.0          super().__init__(data)
   181         1         10.0      10.0      0.0          self.mortgage_rate = 5.2  # rate in percentage

Which is a bit useless, because I don't know what actual parent __init__ function (this class has 2 parents, each of which have one or more parents) is being called.

Is there any way to do this better? For example, is there a way to automatically dive into each line, and profile the lines that get called by it (with limited depth)?

gdlmx
  • 6,479
  • 1
  • 21
  • 39
naught101
  • 18,687
  • 19
  • 90
  • 138
  • It would be really helpful to know why this got down-voted.. If I can add something to the question, I'm happy to. – naught101 Mar 19 '19 at 23:26
  • 1
    parent class is easy to determine by `mro` and will be static at run time unless you are creating classes dynamically at run time. – Arun Karunagath Mar 22 '19 at 17:27

1 Answers1

5

There are many ways:

The trace module

The trace module in the standard python libraries provides a handy function to track the execution of your program, line by line. Therefore it's pretty easy to figure out which function is called by your __init__ method.

Try to run the following codes in a python shell

from MyMod import MyClass
# Do necessary preparation for your module HERE

# --- Setup and start tracing ---
import sys, trace
tracer = trace.Trace( trace=0, count=0, timing=True,  countcallers=True)
tracer.run('MyClass()') # init your class and track the function calls
tracer.results().write_results(show_missing=False) # print result to the screen

The tracer will display the calling relationships exposed by running the program.

MyDependency.Fourth.__init__ -> MyDependency.Second.__init__
MyDependency.Second.__init__ -> MyDependency.Third.__init__
MyDependency.Third.__init__ -> MyDependency.First.__init__
MyClass.Child.__init__ -> MyDependency.Fourth.__init__

The trace module has also a CLI. The above python codes are equivalent to this shell command:

python -m trace -T test.py | grep __init__

where option -T is equivalent to countcallers=True. The target script test.py should contain minimal codes to initialize your class.

Add line-profiler to the invoked functions

Now you know the names of modules, classes and methods which were invoked in your class initialization. Then you can add @profile decorator to those functions. As a side note: It's not necessary to modify the source code of each module for adding the decorator. Simply import them in your main module and run profile.add_function(MyDependency.Third.__init__) will have the same effect.

If you want to get a chronological trace of all lines of python codes that were invoked, use the following options

tracer = trace.Trace( ignoredirs=[sys.prefix, sys.exec_prefix ], trace=1, count=0, timing=True )

It will print out

 --- modulename: MyMod, funcname: __init__
0.00 MyMod.py(6):         super().__init__()
 --- modulename: MyDependency, funcname: __init__
0.00 MyDependency.py(17):         super().__init__()
...

where the first column is the walk clock time.

The sys.setprofile method

You can register a callback function via the sys.setprofile method. It will receive events of stack transition (when a function gets called or returns). Each event comes with a stack frame object, from which you can record the module, class and the function that is invoked.

This method will give you maximum flexibility. For example, you can filter out function calls with stack-depth or the length of execution time. For an usage example, please see my older post for a similar question.

File structure for the above examples

The above results are based on the following module/class structure taken from another post.

File "MyDependency.py"

class First:
    ...
class Second(First):
    ...
class Third(First):
    ...
class Fourth(Second, Third):
    ...

File "MyModel.py"

from MyDependency import Fourth
class MyClass(Fourth):
    def __init__(self):
        super().__init__()
gdlmx
  • 6,479
  • 1
  • 21
  • 39