Navigation
- index
- modules |
- next |
- previous |
- PyMOTW »
- Debugging and Profiling »
Purpose: | Monitor which statements and functions are executed as a program runs to produce coverage and call-graph information. |
---|---|
Available In: | 2.3 and later |
The trace module helps you understand the way your programruns. You can trace the statements executed, produce coveragereports, and investigate the relationships between functions that calleach other.
Command Line Interface¶
It is easy use trace directly from the command line. Given thefollowing Python scripts as input:
from recurse import recursedef main(): print 'This is the main program.' recurse(2) returnif __name__ == '__main__': main()
def recurse(level): print 'recurse(%s)' % level if level: recurse(level-1) returndef not_called(): print 'This function is never called.'
Tracing Execution¶
We can see which statements are being executed as the program runsusing the --trace option.
$ python -m trace --trace trace_example/main.py --- modulename: main, funcname: <module>main.py(7): """main.py(12): from recurse import recurse --- modulename: recurse, funcname: <module>recurse.py(7): """recurse.py(12): def recurse(level):recurse.py(18): def not_called():main.py(14): def main():main.py(19): if __name__ == '__main__':main.py(20): main() --- modulename: main, funcname: mainmain.py(15): print 'This is the main program.'This is the main program.main.py(16): recurse(2) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(2)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(1)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(0)recurse.py(14): if level:recurse.py(16): returnrecurse.py(16): returnrecurse.py(16): returnmain.py(17): return --- modulename: trace, funcname: _unsettracetrace.py(80): sys.settrace(None)
The first part of the output shows some setup operations performed bytrace. The rest of the output shows the entry into eachfunction, including the module where the function is located, and thenthe lines of the source file as they are executed. You can see thatrecurse() is entered three times, as you would expect from theway it is called in main().
Code Coverage¶
Running trace from the command line with the --countoption will produce code coverage report information, so you can seewhich lines are run and which are skipped. Since your program isusually made up of multiple files, a separate coverage report isproduced for each. By default the coverage report files are writtento the same directory as the module, named after the module but with a.cover extension instead of .py.
$ python -m trace --count trace_example/main.pyThis is the main program.recurse(2)recurse(1)recurse(0)
And two output files, trace_example/main.cover:
1: from recurse import recurse 1: def main(): 1: print 'This is the main program.' 1: recurse(2) 1: return 1: if __name__ == '__main__': 1: main()
and trace_example/recurse.cover:
1: def recurse(level): 3: print 'recurse(%s)' % level 3: if level: 2: recurse(level-1) 3: return 1: def not_called(): print 'This function is never called.'
Note
Although the line def recurse(level): has a count of 1,that does not mean the function was only run once. It means thefunction definition was only executed once.
It is also possible to run the program several times, perhaps withdifferent options, to save the coverage data and produce a combinedreport.
$ python -m trace --coverdir coverdir1 --count --file coverdir1/coverage\_report.dat trace_example/main.pySkipping counts file 'coverdir1/coverage_report.dat': [Errno 2] No such file or directory: 'coverdir1/coverage_report.dat'This is the main program.recurse(2)recurse(1)recurse(0)$ python -m trace --coverdir coverdir1 --count --file coverdir1/coverage\_report.dat trace_example/main.pyThis is the main program.recurse(2)recurse(1)recurse(0)$ python -m trace --coverdir coverdir1 --count --file coverdir1/coverage\_report.dat trace_example/main.pyThis is the main program.recurse(2)recurse(1)recurse(0)
Once the coverage information is recorded to the .cover files, youcan produce reports with the --report option.
$ python -m trace --coverdir coverdir1 --report --summary --missing --fi\le coverdir1/coverage_report.dat trace_example/main.pylines cov% module (path) 515 0% trace (/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/trace.py) 8 100% trace_example.main (trace_example/main.py) 8 87% trace_example.recurse (trace_example/recurse.py)
Since the program ran three times, the coverage report shows valuesthree times higher than the first report. The --summaryoption adds the percent covered information to the output above. Therecurse module is only 87% covered. A quick look at the coverfile for recurse shows that the body of not_called() is indeednever run, indicated by the >>>>>> prefix.
3: def recurse(level): 9: print 'recurse(%s)' % level 9: if level: 6: recurse(level-1) 9: return 3: def not_called():>>>>>> print 'This function is never called.'
Calling Relationships¶
In addition to coverage information, trace will collect andreport on the relationships between functions that call each other.
For a simple list of the functions called, use --listfuncs:
$ python -m trace --listfuncs trace_example/main.pyThis is the main program.recurse(2)recurse(1)recurse(0)functions called:filename: /Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/trace.py, modulename: trace, funcname: _unsettracefilename: trace_example/main.py, modulename: main, funcname: <module>filename: trace_example/main.py, modulename: main, funcname: mainfilename: trace_example/recurse.py, modulename: recurse, funcname: <module>filename: trace_example/recurse.py, modulename: recurse, funcname: recurse
For more details about who is doing the calling, use--trackcalls.
$ python -m trace --listfuncs --trackcalls trace_example/main.pyThis is the main program.recurse(2)recurse(1)recurse(0)calling relationships:*** /Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/trace.py *** trace.Trace.runctx -> trace._unsettrace --> trace_example/main.py trace.Trace.runctx -> main.<module>*** trace_example/main.py *** main.<module> -> main.main --> trace_example/recurse.py main.<module> -> recurse.<module> main.main -> recurse.recurse*** trace_example/recurse.py *** recurse.recurse -> recurse.recurse
Programming Interface¶
For a little more control over the trace interface, you can invoke itfrom within your program using a Trace object.Trace lets you set up fixtures and other dependencies beforerunning a single function or execing a Python command to be traced.
import tracefrom trace_example.recurse import recursetracer = trace.Trace(count=False, trace=True)tracer.run('recurse(2)')
Since the example only traces into the recurse() function, noinformation from main.py is included in the output.
$ python trace_run.py --- modulename: trace_run, funcname: <module><string>(1): --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(2)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(1)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(0)recurse.py(14): if level:recurse.py(16): returnrecurse.py(16): returnrecurse.py(16): return
That same output could have been produced with the runfunc()method, too. runfunc() accepts arbitrary positional andkeyword arguments, which are passed to the function when it is calledby the tracer.
import tracefrom trace_example.recurse import recursetracer = trace.Trace(count=False, trace=True)tracer.runfunc(recurse, 2)
$ python trace_runfunc.py --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(2)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(1)recurse.py(14): if level:recurse.py(15): recurse(level-1) --- modulename: recurse, funcname: recurserecurse.py(13): print 'recurse(%s)' % levelrecurse(0)recurse.py(14): if level:recurse.py(16): returnrecurse.py(16): returnrecurse.py(16): return
Saving Result Data¶
Counts and coverage information can be recorded as well, just as withthe command line interface. The data must be saved explicitly, usingthe CoverageResults instance from the Trace object.
import tracefrom trace_example.recurse import recursetracer = trace.Trace(count=True, trace=False)tracer.runfunc(recurse, 2)results = tracer.results()results.write_results(coverdir='coverdir2')
$ python trace_CoverageResults.pyrecurse(2)recurse(1)recurse(0)$ find coverdir2coverdir2coverdir2/trace_example.recurse.cover
And the contents of coverdir2/trace_example.recurse.cover:
#!/usr/bin/env python # encoding: utf-8 # # Copyright (c) 2008 Doug Hellmann All rights reserved. # """>>>>>> """ #__version__ = "$Id$" #end_pymotw_header >>>>>> def recurse(level): 3: print 'recurse(%s)' % level 3: if level: 2: recurse(level-1) 3: return >>>>>> def not_called():>>>>>> print 'This function is never called.'
To save the counts data for generating reports, use the infile andoutfile argument to Trace.
import tracefrom trace_example.recurse import recursetracer = trace.Trace(count=True, trace=False, outfile='trace_report.dat')tracer.runfunc(recurse, 2)report_tracer = trace.Trace(count=False, trace=False, infile='trace_report.dat')results = tracer.results()results.write_results(summary=True, coverdir='/tmp')
Pass a filename to infile to read previously stored data, and afilename to outfile to write new results after tracing. If infileand outfile are the same, it has the effect of updating the filewith cummulative data.
$ python trace_report.pyrecurse(2)recurse(1)recurse(0)lines cov% module (path) 8 50% trace_example.recurse (/Users/dhellmann/Documents/PyMOTW/src/PyMOTW/trace/trace_example/recurse.py)
Trace Options¶
The constructor for Trace takes several optional parametersto control runtime behavior.
- count
- Boolean. Turns on line number counting. Defaults to True.
- countfuncs
- Boolean. Turns on list of functions called during the run.Defaults to False.
- countcallers
- Boolean. Turns on tracking for callers and callees. Defaults toFalse.
- ignoremods
- Sequence. List of modules or packages to ignore when trackingcoverage. Defaults to an empty tuple.
- ignoredirs
- Sequence. List of directories containing modules or packages to beignored. Defaults to an empty tuple.
- infile
- Name of the file containing cached count values. Defaults to None.
- outfile
- Name of the file to use for storing cached count files. Defaults toNone, and data is not stored.
See also
- trace
- Standard library documentation for this module.
- Tracing a Program As It Runs
- The sys module includes facilities for adding your owntracing function to the interpreter at run-time.
- coverage.py
- Ned Batchelder’s coverage module.
- figleaf
- Titus Brown’s coverage app.
Navigation
- index
- modules |
- next |
- previous |
- PyMOTW »
- Debugging and Profiling »
© Copyright Doug Hellmann. | | Last updated on Jul 11, 2020. | Created using Sphinx. | Design based on "Leaves" by SmallPark |