Braindump: Use a Decorator to Time your Python Function

Posted by in Software

In the programs I write these days I use timing methods to profile the code, mainly because I find it easier to split and sum deltas based on functions. For example, I have a script that loads an XML file, parses it into a relational-ish layout, and uploads the layout into a database. Therefore, I end up having to interlace my code with start-end sequences, sums and so on. This approach makes everything more difficult to read and maintain.

A Solution

If you can arrange your code to measure execution time at a function level, you can use a decorator for that function. The code I found on the ‘net is:

An example of execution is:

Once the function has finished executing, the result will be printed like:

Advantages

There are some advantages to this:

  • This approach allows you to structure your code on measurable chunks. I found the resulted functions are well isolated and can be chained nicely.
  • You can customise the output e.g. to generate a log. This way, you can use it to aggregate e.g. high frequency functions. For example, I isolated the reading, DOM building, parsing and DB insertion in separate functions, called many times. I could use the output via grep/gnuplot to check if any of the operations would degrade in time as well as to extrapolate loading time for the whole dataset.
  • It does make the code easier to read (as compared to inline timing statements)
  • You can remove the core easier once analysis has been done

Disadvantages

  • Python has a bunch of profiling tools. Using them slows down your code execution, but don’t require any coding
  • I find decorators a bit more opaque than inline code; I usually go through the decorator’s code to see what actually does. Sometimes it takes a while longer to figure it out.

Conclusion

if you isolate your code in functions and are happy to have function-level granularity, use it. If you want more info, you’d need either to code timing inline with your own code or use e.g. profiling.

HTH,

PS: All credit goes to Andreas Jung for the code. I’m just dumping it here for my reference.


A little experiment: If you find this post and ad below useful, please check the ad out :-)