g.SherlockTracer

[Edward K. Ream]

Recent revs contain work on a nifty new tracing tool: the SherlockTracer class in leoGlobals.py.  This is a stand-alone class: it is not a subclass of pdb.Pdb, and it requires no imports (it does it's own imports)

In essence, the SherlockTracer class does everything my old Sherlock tracing tool did, and it's a lot more flexible.  The idea is that you can enable and disable traces for any method or function with tracing arguments.  Here is the code that I am using to trace the execution of the Rope refactoring tool::

    sherlock = g.SherlockTracer(verbose=True,
        patterns=['+.*','+:.*','-:.*\\lib\\.*','+:.*rope.*','-:.*leoGlobals.py',
            '-:.*worder.py','-:.*prefs.py','-:.*resources.py',])
    sherlock.run()
    try:
        << rope code to be traced >>
    finally:
        sherlock.stop()
        sherlock.print_stats(patterns=['+:.*rope.*',])

The arguments in the pattern lists determine which functions get traced or which stats get printed.  Each pattern starts with "+", "-", "+:" or "-:", followed by a regular expression.

"+x" Enables tracing (or stats) for all functions/methods whose name matches the regular expression x.
"-x" Disables tracing for functions/methods.
"+:x" Enables tracing for all functions in the **file** whose name matches x.
"-:x" Disables tracing for an entire file.

The cute part is that enabling and disabling depends on the order of arguments in the pattern list. Consider the arguments for the Rope trace::

    patterns=['+.*','+:.*','-:.*\\lib\\.*','+:.*rope.*','-:.*leoGlobals.py',
            '-:.*worder.py','-:.*prefs.py','-:.*resources.py',])

This enables tracing for everything, then disables tracing for all library modules, except for all rope modules.  Finally, it disables the tracing for Rope's worder, prefs and resources modules.  Btw, this is one of the best uses for regular expressions that I know of.

Being able to zero in on the code of interest can be a big help in studying other people's code.  This is a non-invasive method: no tracing code needs to be inserted anywhere.

Here is a snippet of a recent trace of Rope's validate call::

    .project.py:validate
    ..project.py:<lambda>
    ...project.py:get_resource
    ....project.py:_get_resource_path
    ..project.py:validate
    ...resourceobserver.py:validate
    ....project.py:_invalid
    ...resourceobserver.py:validate
    ....resourceobserver.py:__init__
    ....resourceobserver.py:_search_resource_moves
    ....resourceobserver.py:_search_resource_changes
    ....resourceobserver.py:_search_resource_creations
    ....resourceobserver.py:_perform_changes
    ...resourceobserver.py:validate
    ....resourceobserver.py:__init__
    ....resourceobserver.py:_search_resource_moves
    ....resourceobserver.py:_search_resource_changes
    ....resourceobserver.py:_search_resource_creations
    ....resourceobserver.py:_perform_changes
    ...resourceobserver.py:validate
   
The leading dots (level dots) indicate the level of nesting of the calls.  The call to project.py:validate is the top-level call: it has only one level dot.  With this kind of trace it is easy to see who calls whom.

Without the verbose argument, the filenames would be omitted from the trace.

That's about it.  I'll probably be adding features to g.SherlockTracer in the next few days.

Edward

[Brian Theado]

Edward,

On Thu, Nov 29, 2012 at 7:41 AM, Edward K. Ream <edre...@gmail.com> wrote:

Recent revs contain work on a nifty new tracing tool: the SherlockTracer class in leoGlobals.py.  This is a stand-alone class: it is not a subclass of pdb.Pdb, and it requires no imports (it does it's own imports)

[...] 

Being able to zero in on the code of interest can be a big help in studying other people's code.  This is a non-invasive method: no tracing code needs to be inserted anywhere.

[...] 

How does this compare to the python trace module (http://docs.python.org/2/library/trace.html)? It looks to me like sherlock filters are more powerful as trace supports only 'ignoremods' and 'ignoredirs'. Maybe there are other differences as well.

Last year I wrote some code which inserts call tree output from the trace module into leo headlines. If it sees the same function in multiple places in the call tree, then it uses clones to avoid duplication. Having the calltree in headlines makes it convenient to only expand those nodes which are of interest.  I posted the code here: https://groups.google.com/d/topic/leo-editor/yLRMXw4Yvv4/discussion (as mentioned there, my code was inspired by Ville's code in scripts.leo).

Brian

[Edward K. Ream]

On Sat, Dec 1, 2012 at 9:07 AM, Brian Theado <brian....@gmail.com> wrote:

[...] 

How does this compare to the python trace module (http://docs.python.org/2/library/trace.html)? It looks to me like sherlock filters are more powerful as trace supports only 'ignoremods' and 'ignoredirs'. Maybe there are other differences as well.

Presumably, it would be possible to subclass trace.Trace to enable on a def by def basis.  Similar remarks apply to Python's logger classes.  Simply having logging "levels" is feeble.

Last year I wrote some code which inserts call tree output from the trace module into leo headlines. If it sees the same function in multiple places in the call tree, then it uses clones to avoid duplication. Having the calltree in headlines makes it convenient to only expand those nodes which are of interest.  I posted the code here: https://groups.google.com/d/topic/leo-editor/yLRMXw4Yvv4/discussion (as mentioned there, my code was inspired by Ville's code in scripts.leo).

There is also the g.Tracer class.  The docstring is:

    '''A "debugger" that computes a call graph.

    To trace a function and its callers, put the following at the function's start:

    g.startTracer()
    '''

Did you have a hand in this?

Brian

e code of interest can be a big help in studying other people's code.  This is a non-invasive method: no tracing code needs to be inserted anywhere.

Imo, this is the biggest plus.

Edward