Some tests are failing with Python 3.10 beta 1

[frenzymadness]

Hello.

It seems that some parts of PySnooper produce different results in Python 3.10 beta 1 and therefore 9 tests fail:

================================== short test summary info ===================================
FAILED tests/test_pysnooper.py::test_relative_time - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_with_block[True] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_with_block[False] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_with_block_depth[True] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_with_block_depth[False] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_cellvars[True] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_cellvars[False] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_var_order[True] - tests.utils.OutputFailure: 
FAILED tests/test_pysnooper.py::test_var_order[False] - tests.utils.OutputFailure: 
========================= 9 failed, 65 passed, 21 warnings in 1.47s ==========================

But, I've tried to reproduce the issue manually and I have to admit that I see no real difference between the output of a simple script run via Python 3.9 and 3.10. Might it be caused by something internal in tests?

[hroncok]

Do you run beta 1? Because it used to work with alpha 7.

[frenzymadness]

Yes. I guess that the switch from alpha 7 to beta 1 is the reason why I did not get this report earlier.

[alexmojaki]

The tests for my fork snoop make it a little easier to see the difference: https://github.com/alexmojaki/snoop/commit/f83c0ae6767f3873c03f5d1c4a0af7fc96ae3219

Looks like the main difference is that the with line gets revisited on exiting. I saw something recently about sys.settrace visiting lines more thoroughly, that's probably why this is happening.

[frenzymadness]

You are right, when I use a with block, there is one more line in Python 3.10:

Code

import pysnooper

@pysnooper.snoop()
def f(foo):
    with open("cool", mode="w") as f:
        f.write(foo)

f("bar")

Python 3.9:

Source path:... /home/lbalhar/Software/PySnooper/tests/simple.py
Starting var:.. foo = 'bar'
07:26:57.610152 call         4 def f(foo):
07:26:57.610359 line         5     with open("cool", mode="w") as f:
New var:....... f = <_io.TextIOWrapper name='cool' mode='w' encoding='UTF-8'>
07:26:57.610477 line         6         f.write(foo)
07:26:57.610580 return       6         f.write(foo)
Return value:.. None
Elapsed time: 00:00:00.000519

Python 3.10:

Source path:... /home/lbalhar/Software/PySnooper/tests/simple.py
Starting var:.. foo = 'bar'
07:26:53.654138 call         4 def f(foo):
07:26:53.654488 line         5     with open("cool", mode="w") as f:
New var:....... f = <_io.TextIOWrapper name='cool' mode='w' encoding='UTF-8'>
07:26:53.654662 line         6         f.write(foo)
07:26:53.654769 line         5     with open("cool", mode="w") as f:
07:26:53.654924 return       5     with open("cool", mode="w") as f:
Return value:.. None
Elapsed time: 00:00:00.000940

Diff

--- 39  2021-05-12 07:26:57.610222230 +0200
+++ 310 2021-05-12 07:26:53.654228636 +0200
@@ -1,9 +1,10 @@
 Source path:... /home/lbalhar/Software/PySnooper/tests/simple.py
 Starting var:.. foo = 'bar'
-07:26:57.610152 call         4 def f(foo):
-07:26:57.610359 line         5     with open("cool", mode="w") as f:
+07:26:53.654138 call         4 def f(foo):
+07:26:53.654488 line         5     with open("cool", mode="w") as f:
 New var:....... f = <_io.TextIOWrapper name='cool' mode='w' encoding='UTF-8'>
-07:26:57.610477 line         6         f.write(foo)
-07:26:57.610580 return       6         f.write(foo)
+07:26:53.654662 line         6         f.write(foo)
+07:26:53.654769 line         5     with open("cool", mode="w") as f:
+07:26:53.654924 return       5     with open("cool", mode="w") as f:
 Return value:.. None
-Elapsed time: 00:00:00.000519
+Elapsed time: 00:00:00.000940

And after some sleep, I finally understand the output of the tests. The most important is the very end where the with statement makes the difference:

E           Return value:.. None                                                                                ReturnValueEntry(prefix='')  
E           New var:....... result = None                                                                       ElapsedTimeEntry(tolerance=0.2, prefix='')  <===
E           07:36:52.884986 line      1270     with pysnooper.snoop(string_io, depth=2, normalize=normalize):     <===
E           Elapsed time: 00:00:00.000289                                                                         <===
E           Output has 25 lines, while we expect 23 lines.

So, to fix the test_var_order these two lines are needed:

diff --git a/tests/test_pysnooper.py b/tests/test_pysnooper.py
index 882b5ea..86fe386 100644
--- a/tests/test_pysnooper.py
+++ b/tests/test_pysnooper.py
@@ -1298,6 +1298,8 @@ def test_var_order(normalize):
             VariableEntry("seven", "7"),
             ReturnEntry(),
             ReturnValueEntry(),
+            VariableEntry("result", "None"),
+            LineEntry(source_regex="with pysnooper.snoop.*"),
             ElapsedTimeEntry(),
         ),
         normalize=normalize,

The question here is how to fix all of the failing tests and keep compatibility with older Pythons. It's possible to add a condition and update the tuples with entries for Python 3.10 but there might be a better and nicer solution.

[cool-RR]

Hi Lumír! I'm happy to see you again, and thank you for this in-depth analysis.

What do you think about adding an argument max_python_version to _BaseEntry and thus to all its subclasses (like VariableEntry, LineEntry, etc.) Then, when the Python version is higher than the given version, these entries become no-ops.

Will this solve the problem?

[frenzymadness]

Sounds interesting. I'd also add a min_python_version argument so you would be able to specify both limits to an entry and therefore test the line only for a specific range of Python versions.

I'll take a look at this solution.