Remember state of the local vars beforehand

[alexbers]

Now the local variables state is examined when the first callback fires. This can be too late, when the variables were created earlier, before the call. For example this code:

import pysnooper
import sys

class C:
    pass

def f():
    pass

a = 1

with pysnooper.snoop(depth=2):
    2 + 2

produces this output

New var:....... __name__ = '__main__'
New var:....... __doc__ = None
New var:....... __package__ = None
New var:....... __loader__ = <_frozen_importlib_external.SourceFileLoader object at 0x7f015d3adfd0>
New var:....... __spec__ = None
New var:....... __annotations__ = {}
New var:....... __builtins__ = <module 'builtins' (built-in)>
New var:....... __file__ = 'q.py'
New var:....... __cached__ = None
New var:....... pysnooper = <module 'pysnooper' from '/home/bay/tmp/249_pysnooper/PySnooper/pysnooper/__init__.py'>
New var:....... sys = <module 'sys' (built-in)>
New var:....... C = <class '__main__.C'>
New var:....... f = <function f at 0x7f015d3e61e0>
New var:....... a = 1
00:51:25.580167 line        14     2 + 2

Here we can see functions, classes, modules, and special variables, declared earlier.

The idea of this one-line patch is to remember the local variables state before the first call, in the __enter__ function:

        self.frame_to_local_reprs[calling_frame] = get_local_reprs(calling_frame)

This adds the symmetry with the __exit__ function, because it contains

        self.frame_to_local_reprs.pop(calling_frame, None)

and also solves the problem:

00:51:43.395931 line        14     2 + 2

[alexmojaki]

If I understand correctly, this is only relevant when using with, not for decorators, right?

At the very least this seems like a bad idea if the code being traced directly uses variables that appeared beforehand, which your example misses because 2+2 doesn't have any variables. If it had x = foo(a) I'd be interested in what a is.

Hypothetically any variable could be relevant, e.g. if the code uses locals() or calls a function which references a variable through a closure, e.g. if you had def f(): return a*2 up there.

[alexbers]

If we had this code

import pysnooper

with pysnooper.snoop():
    c = 2 + 2
    d = 4

this output will be returned:

01:24:42.374239 line         4     c = 2 + 2
New var:....... c = 4
01:24:42.374446 line         5     d = 4

As you can see there is no "d" in the output. This is a bug of both old and new versions - the very last line not printed. I am looking for a good way how to fix it. May be send a fake trace event in the __exit__ or try to find more elegant solution..

[alexbers]

If we use the tracer with decorators the first event we get it is "call" event. This causes the local variables to be empty, so the bug doesn't occur with decorators.

[alexbers]

At the very least this seems like a bad idea if the code being traced directly uses variables that appeared beforehand, which your example misses because 2+2 doesn't have any variables. If it had x = foo(a) I'd be interested in what a is.

We can still see the a variable:

import pysnooper

def foo(a):
    pass

a = 100
with pysnooper.snoop(depth=2):
    x = foo(a)

01:33:52.575224 line         8     x = foo(a)
Starting var:.. a = 100
01:33:52.575396 call         3 def foo(a):
01:33:52.575458 line         4     pass
01:33:52.575511 return       4     pass
Return value:.. None

[alexmojaki]

Only if you set some depth (which might add any number of unwanted lines to the output), and even then only if you enter a user defined function. It wouldn't work for just a*2 or max(a).

[alexbers]

Could you please provide an example with a*2 or max(a), where the old version behaves better?

[alexmojaki]

import re

import pysnooper

def main():
    string = 'hello world'
    pattern = re.compile('world')
    with pysnooper.snoop(depth=2):
        match = pattern.match(string)
        if match:
            print('success')

main()

New var:....... string = 'hello world'
New var:....... pattern = re.compile('world')
22:56:51.705671 line        10         match = pattern.match(string)
New var:....... match = None
22:56:51.705895 line        11         if match:

I haven't tested on your version, but it doesn't show string and pattern, right?

[alexbers]

No, but if you want to have it shown you can modify the code as

import re
import pysnooper

def main():
    with pysnooper.snoop():
        string = 'hello world'
        pattern = re.compile('world')
        match = pattern.match(string)
        if match:
            print('success')
main()

[alexmojaki]

What about:

import re

import pysnooper

def check(string):
    pattern = re.compile('world')
    with pysnooper.snoop(depth=2):
        match = pattern.match(string)
        if match:
            print('success')

check('hello world')

You can definitely find ways to see the variables, but it takes effort and maybe even a little imagination. Maybe that's not a big deal, maybe it is.

[alexbers]

Your example looks good because you have only one local variable and a small function. Whole check function can be just decorated with @pysnooper.Snoop() and the output should be nice enough.

Using the with-construction in the code works the best, where a function is so large that the produced output is big. Large functions usually have a lot of local variables and searching among dozens of them is troublesome.

In this case a watch functionality is useful to get values of interesting vars, including the global ones.

Another use-case of with-constructions are tracing the parts of for-loops:

import pysnooper

def main():
    a, b, c, d = 1, 2, 3, 4  # ...

    c = 0
    for i in range(4):
        with pysnooper.snoop():
            c += i
            2 + 2

main()

In this case it writes all local variables every time:

New var:....... a = 1
New var:....... b = 2
New var:....... c = 0
New var:....... d = 4
New var:....... i = 0
03:25:19.835535 line        10             c += i
03:25:19.835678 line        11             2 + 2
New var:....... a = 1
New var:....... b = 2
New var:....... c = 0
New var:....... d = 4
New var:....... i = 1
03:25:19.835823 line         9         with pysnooper.snoop():
03:25:19.835875 line        10             c += i
Modified var:.. c = 1
03:25:19.835933 line        11             2 + 2
New var:....... a = 1
New var:....... b = 2
New var:....... c = 1
New var:....... d = 4
New var:....... i = 2
03:25:19.836059 line         9         with pysnooper.snoop():
03:25:19.836105 line        10             c += i
Modified var:.. c = 3
03:25:19.836161 line        11             2 + 2
New var:....... a = 1
New var:....... b = 2
New var:....... c = 3
New var:....... d = 4
New var:....... i = 3
03:25:19.836284 line         9         with pysnooper.snoop():
03:25:19.836329 line        10             c += i
Modified var:.. c = 6
03:25:19.836392 line        11             2 + 2

With the patch:

03:27:36.412878 line        10             c += i
03:27:36.413031 line        11             2 + 2
03:27:36.413161 line         9         with pysnooper.snoop():
03:27:36.413234 line        10             c += i
Modified var:.. c = 1
03:27:36.413320 line        11             2 + 2
03:27:36.413449 line         9         with pysnooper.snoop():
03:27:36.413508 line        10             c += i
Modified var:.. c = 3
03:27:36.413592 line        11             2 + 2
03:27:36.413720 line         9         with pysnooper.snoop():
03:27:36.413780 line        10             c += i
Modified var:.. c = 6
03:27:36.413862 line        11             2 + 2

[cool-RR]

@alexbers the repeated with inside the loop isn't an important use case in my opinion. Also the long variable dump in your original message is a bit annoying, but I in my opinion not that bad, more information is better than less for this tool.

Unless you've got some other case or example that's more relevant, I'm in favor of rejecting this PR.

[alexbers]

I tried to find a good example in this file: https://chromium.googlesource.com/chromiumos/third_party/portage_tool/+/cros/2.1.9/pym/_emerge/depgraph.py. This is a part of the Gentoo linux build system which calculates the dependencies between packages and it has a really complex logic.

I failed to find any places where using the with-construction is better then just decorating the whole function. As you can see, the most interesting places to trace are inside the while and for loops.

If with-construction inside the loop is a not important use case, that means I misunderstand how the with-construction should be used.

The only use-cases I know are when decorating is not possible (e.g. the code is not inside the function) or when the whole function is too complex to decorate (complex functions have many local variables and/or a lot of code in loop constructions). To I think this pull request can be rejected.

When I tried to debug big functions with the with-construction I noticed one problem: the interesting code should be indented. On active debugging, during continuous re-indenting, I accidentally changed the meaning of the original code several times.

I figured out that it is more convenient to paste this line, before the interesting code instead of reindenting it:

import pysnooper; pysnooper.snoop().__enter__()

This traces till the end of the function or till the __exit__ call. But if user forgot to call __exit__(), it will be the memory leak.

I came to this idea: what if to add the pysnooper.start() and pysnooper.stop() functions. If the user forget to call stop(), do the stopping automatically on the function end. This makes the debugging just as simple as

def f():
  # code
  import pysnooper; pysnooper.start()
  # ... code ... 

To make it work it is possible to create a Snoop object with custom __del__ method and add it as attribute of current frame, which calls __exit__. Or it is possible to catch return event from the current frame and do the cleaning up.

What do you think about it?

[cool-RR]

I think this PR strayed too far from known use cases. I'll close it until we'll have more feedback from users.

Anyway, thanks for your indepth research into this issue. This could be useful in the future.