trace – Follow Python statements as they are executed (2024)

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. | trace – Follow Python statements as they are executed (1) | Last updated on Jul 11, 2020. | Created using Sphinx. | Design based on "Leaves" by SmallPark |

trace – Follow Python statements as they are executed (2024)
Top Articles
Latest Posts
Recommended Articles
Article information

Author: Prof. Nancy Dach

Last Updated:

Views: 5659

Rating: 4.7 / 5 (57 voted)

Reviews: 88% of readers found this page helpful

Author information

Name: Prof. Nancy Dach

Birthday: 1993-08-23

Address: 569 Waelchi Ports, South Blainebury, LA 11589

Phone: +9958996486049

Job: Sales Manager

Hobby: Web surfing, Scuba diving, Mountaineering, Writing, Sailing, Dance, Blacksmithing

Introduction: My name is Prof. Nancy Dach, I am a lively, joyous, courageous, lovely, tender, charming, open person who loves writing and wants to share my knowledge and understanding with you.