Python: Profiler

Problem Statement:

Profiling your python script.

A profiler is a program that monitors performance of a program during run time and provides a lot of information on the program.

Yes a module in Python that can do it easily for you!

Solution - Case Study:

Let's profile the Service class that I posted just before this blog.

Steps:

1. On the cmd prompt goto the Python installation directory.

2. Execute the command: python.exe -m cProfile Services.py

Output of the profiler:

907 function calls (893 primitive calls) in 0.105 CPU seconds

Ordered by: standard name

ncalls tottime percall cumtime percall filename:lineno(function)

1 0.000 0.000 0.000 0.000 :1()

1 0.000 0.000 0.000 0.000 :1(error)

1 0.000 0.000 0.000 0.000 :11(com_error)

1 0.000 0.000 0.000 0.000 :2(__init__)

1 0.000 0.000 0.000 0.000 CLSIDToClass.py:18()

1 0.000 0.000 0.000 0.000 CLSIDToClass.py:48(HasClass)

1 0.003 0.003 0.104 0.104 Services.py:1()

1 0.000 0.000 0.000 0.000 Services.py:8(Services)

1 0.000 0.000 0.000 0.000 __init__.py:116(CDispatch)

1 0.000 0.000 0.000 0.000 __init__.py:161(Constants)

1 0.000 0.000 0.000 0.000 __init__.py:164(__init__)

1 0.000 0.000 0.002 0.002 __init__.py:18(__WrapDispatch)

1 0.000 0.000 0.000 0.000 __init__.py:190(EventsProxy)

1 0.000 0.000 0.000 0.000 __init__.py:26(SetupEnvironment)

1 0.000 0.000 0.000 0.000 __init__.py:417(DispatchBaseClass)

1 0.000 0.000 0.035 0.035 __init__.py:46(GetObject)

1 0.000 0.000 0.000 0.000 __init__.py:493(CoClassBaseClass)

1 0.013 0.013 0.036 0.036 __init__.py:5()

1 0.000 0.000 0.035 0.035 __init__.py:83(Moniker)

1 0.002 0.002 0.022 0.022 __init__.py:9()

1 0.000 0.000 0.000 0.000 build.py:102(__init__)

1 0.003 0.003 0.003 0.003 build.py:11()

1 0.000 0.000 0.000 0.000 build.py:34(NotSupportedException)

1 0.000 0.000 0.000 0.000 build.py:388(VTableItem)

1 0.000 0.000 0.000 0.000 build.py:411(LazyDispatchItem)

1 0.000 0.000 0.000 0.000 build.py:413(__init__)

1 0.000 0.000 0.000 0.000 build.py:53(MapEntry)

1 0.000 0.000 0.000 0.000 build.py:84(OleItem)

1 0.000 0.000 0.000 0.000 build.py:87(__init__)

1 0.000 0.000 0.000 0.000 build.py:99(DispatchItem)

1 0.000 0.000 0.000 0.000 dynamic.py:110(Dispatch)

1 0.000 0.000 0.000 0.000 dynamic.py:131(MakeOleRepr)

1 0.000 0.000 0.000 0.000 dynamic.py:161(CDispatch)

1 0.000 0.000 0.000 0.000 dynamic.py:162(__init__)

1 0.009 0.009 0.012 0.012 dynamic.py:17()

1 0.000 0.000 0.000 0.000 dynamic.py:79(_GetGoodDispatch)

1 0.000 0.000 0.000 0.000 dynamic.py:90(_GetGoodDispatchAndUserName)

1 0.000 0.000 0.000 0.000 fnmatch.py:11()

1 0.000 0.000 0.000 0.000 gencache.py:165(GetClassForCLSID)

1 0.000 0.000 0.000 0.000 gencache.py:204(GetModuleForCLSID)

1 0.005 0.005 0.008 0.008 gencache.py:22()

1 0.000 0.000 0.000 0.000 gencache.py:53(__init__)

1 0.000 0.000 0.000 0.000 gencache.py:73(_LoadDicts)

1 0.001 0.001 0.002 0.002 glob.py:1()

1 0.000 0.000 0.000 0.000 keyword.py:11()

5 0.000 0.000 0.000 0.000 ntpath.py:116(splitdrive)

1 0.000 0.000 0.000 0.000 ntpath.py:267(isdir)

1 0.000 0.000 0.000 0.000 ntpath.py:439(normpath)

1 0.000 0.000 0.000 0.000 ntpath.py:495(abspath)

4 0.000 0.000 0.000 0.000 ntpath.py:51(isabs)

3 0.000 0.000 0.000 0.000 ntpath.py:59(join)

1 0.003 0.003 0.022 0.022 pythoncom.py:2()

1 0.000 0.000 0.003 0.003 pywintypes.py:2()

2 0.003 0.002 0.019 0.009 pywintypes.py:3(__import_pywin32_system_module__)

2 0.000 0.000 0.004 0.002 re.py:186(compile)

2 0.000 0.000 0.004 0.002 re.py:227(_compile)

2 0.000 0.000 0.000 0.000 sre_compile.py:184(_compile_charset)

2 0.000 0.000 0.000 0.000 sre_compile.py:213(_optimize_charset)

6 0.000 0.000 0.000 0.000 sre_compile.py:24(_identityfunction)

2 0.000 0.000 0.000 0.000 sre_compile.py:264(_mk_bitmap)

2 0.000 0.000 0.001 0.000 sre_compile.py:367(_compile_info)

6/2 0.000 0.000 0.001 0.000 sre_compile.py:38(_compile)

4 0.000 0.000 0.000 0.000 sre_compile.py:480(isstring)

2 0.000 0.000 0.002 0.001 sre_compile.py:486(_code)

2 0.000 0.000 0.004 0.002 sre_compile.py:501(compile)

4 0.000 0.000 0.000 0.000 sre_parse.py:132(__len__)

36 0.000 0.000 0.000 0.000 sre_parse.py:136(__getitem__)

46 0.000 0.000 0.000 0.000 sre_parse.py:144(append)

6/2 0.000 0.000 0.000 0.000 sre_parse.py:146(getwidth)

2 0.000 0.000 0.000 0.000 sre_parse.py:184(__init__)

58 0.000 0.000 0.001 0.000 sre_parse.py:188(__next)

12 0.000 0.000 0.000 0.000 sre_parse.py:201(match)

53 0.000 0.000 0.001 0.000 sre_parse.py:207(get)

3/2 0.000 0.000 0.002 0.001 sre_parse.py:307(_parse_sub)

5/2 0.000 0.000 0.002 0.001 sre_parse.py:385(_parse)

2 0.000 0.000 0.002 0.001 sre_parse.py:669(parse)

2 0.000 0.000 0.000 0.000 sre_parse.py:73(__init__)

1 0.000 0.000 0.000 0.000 sre_parse.py:78(opengroup)

1 0.000 0.000 0.000 0.000 sre_parse.py:89(closegroup)

6 0.000 0.000 0.000 0.000 sre_parse.py:96(__init__)

2 0.000 0.000 0.000 0.000 struct.py:35(_compile)

2 0.000 0.000 0.000 0.000 struct.py:54(pack)

2 0.000 0.000 0.000 0.000 struct.py:77(unpack)

1 0.000 0.000 0.000 0.000 traceback.py:1()

1 0.000 0.000 0.000 0.000 winerror.py:4()

1 0.000 0.000 0.000 0.000 wmi.py:101(SelfDeprecatingDict)

1 0.000 0.000 0.000 0.000 wmi.py:1143(_wmi_watcher)

1 0.000 0.000 0.000 0.000 wmi.py:138(ProvideConstants)

1 0.000 0.000 0.000 0.000 wmi.py:144(__init__)

4 0.000 0.000 0.000 0.000 wmi.py:149(__getattr__)

1 0.000 0.000 0.000 0.000 wmi.py:168(x_wmi)

1 0.000 0.000 0.000 0.000 wmi.py:183(x_wmi_invalid_query)

1 0.000 0.000 0.000 0.000 wmi.py:187(x_wmi_timed_out)

1 0.000 0.000 0.000 0.000 wmi.py:191(x_wmi_no_namespace)

1 0.000 0.000 0.000 0.000 wmi.py:197(x_access_denied)

1 0.000 0.000 0.000 0.000 wmi.py:201(x_wmi_authentication)

1 0.000 0.000 0.000 0.000 wmi.py:205(x_wmi_uninitialised_thread)

1 0.000 0.000 0.000 0.000 wmi.py:324(_wmi_method)

1 0.000 0.000 0.000 0.000 wmi.py:432(_wmi_property)

1 0.000 0.000 0.000 0.000 wmi.py:450(_wmi_object)

1 0.000 0.000 0.003 0.003 wmi.py:733(_wmi_event)

1 0.000 0.000 0.000 0.000 wmi.py:756(_wmi_class)

1 0.005 0.005 0.101 0.101 wmi.py:77()

1 0.000 0.000 0.000 0.000 wmi.py:870(_wmi_result)

1 0.000 0.000 0.000 0.000 wmi.py:886(_wmi_namespace)

2 0.000 0.000 0.000 0.000 wmi.py:91(signed_to_unsigned)

2 0.000 0.000 0.000 0.000 {_sre.compile}

2 0.000 0.000 0.000 0.000 {_win32sysloader.GetModuleFilename}

1 0.001 0.001 0.001 0.001 {_win32sysloader.LoadModule}

2 0.000 0.000 0.000 0.000 {built-in method load}

1 0.000 0.000 0.000 0.000 {cPickle.Unpickler}

2 0.000 0.000 0.000 0.000 {dir}

1 0.001 0.001 0.105 0.105 {execfile}

2 0.000 0.000 0.000 0.000 {getattr}

2 0.000 0.000 0.000 0.000 {globals}

4 0.000 0.000 0.000 0.000 {hasattr}

2 0.000 0.000 0.000 0.000 {imp.get_suffixes}

2 0.015 0.007 0.015 0.007 {imp.load_dynamic}

1 0.000 0.000 0.000 0.000 {imp.new_module}

7 0.000 0.000 0.000 0.000 {isinstance}

171/169 0.000 0.000 0.000 0.000 {len}

3 0.000 0.000 0.000 0.000 {max}

4 0.000 0.000 0.000 0.000 {method 'Bind' of 'PyITypeComp' objects}

1 0.000 0.000 0.000 0.000 {method 'BindToObject' of 'PyIMoniker' objects}

1 0.000 0.000 0.000 0.000 {method 'GetContainingTypeLib' of 'PyITypeInfo' objects}

2 0.000 0.000 0.000 0.000 {method 'GetTypeAttr' of 'PyITypeInfo' objects}

1 0.000 0.000 0.000 0.000 {method 'GetTypeComp' of 'PyITypeInfo' objects}

1 0.000 0.000 0.000 0.000 {method 'GetTypeComp' of 'PyITypeLib' objects}

2 0.001 0.001 0.001 0.001 {method 'GetTypeInfo' of 'PyIDispatch' objects}

230 0.000 0.000 0.000 0.000 {method 'append' of 'list' objects}

1 0.000 0.000 0.000 0.000 {method 'clear' of 'dict' objects}

1 0.000 0.000 0.000 0.000 {method 'close' of 'file' objects}

1 0.000 0.000 0.000 0.000 {method 'difference' of 'set' objects}

1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}

4 0.000 0.000 0.000 0.000 {method 'extend' of 'list' objects}

2 0.000 0.000 0.000 0.000 {method 'get' of 'dict' objects}

2 0.000 0.000 0.000 0.000 {method 'items' of 'dict' objects}

1 0.000 0.000 0.000 0.000 {method 'join' of 'str' objects}

1 0.000 0.000 0.000 0.000 {method 'lstrip' of 'str' objects}

1 0.000 0.000 0.000 0.000 {method 'remove' of 'list' objects}

1 0.000 0.000 0.000 0.000 {method 'replace' of 'str' objects}

1 0.000 0.000 0.000 0.000 {method 'split' of 'str' objects}

7 0.000 0.000 0.000 0.000 {method 'startswith' of 'str' objects}

2 0.000 0.000 0.000 0.000 {method 'unpack' of 'Struct' objects}

15 0.000 0.000 0.000 0.000 {min}

1 0.000 0.000 0.000 0.000 {nt._getfullpathname}

1 0.000 0.000 0.000 0.000 {nt.stat}

1 0.000 0.000 0.000 0.000 {open}

46 0.000 0.000 0.000 0.000 {ord}

1 0.033 0.033 0.033 0.033 {pythoncom.MkParseDisplayName}

1 0.000 0.000 0.000 0.000 {win32api.GetFullPathName}

1 0.000 0.000 0.000 0.000 {win32api.GetTempPath}

1 0.000 0.000 0.000 0.000 {win32api.RegOpenKey}

So many function calls for a class! Wow!

More information on the profiler here