[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Change by Serhiy Storchaka :


--
resolution:  -> fixed
stage: patch review -> resolved
status: open -> closed

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:


New changeset 95b6acf951fa7f503a3cc5ce7d969d7bcf2f95c9 by Serhiy Storchaka in 
branch 'master':
bpo-34876: Change the lineno of the AST for decorated function and class. 
(GH-9731)
https://github.com/python/cpython/commit/95b6acf951fa7f503a3cc5ce7d969d7bcf2f95c9


--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ned Batchelder]

Ned Batchelder  added the comment:

Thanks, the fix looks good to me.

I made a comparison of some decorator tracing to check it out:  
https://gist.github.com/nedbat/d603a34136299f0c0b8e442fccadeb7d

TBH, the first time I tried it, something seemed wrong, but I can't see it now, 
so ¯\_(ツ)_/¯  :)

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

Ned, please look at PR 9731. Does it fixes the issue to you?

Georg, you had added the original code for patching the lineno of decorated 
function. Are your good to remove this patch and to move updating the first 
line number at the code generation stage?

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

See 09aaa88328a5083469b2682230c7f3c62942afab. The position of the AST node for 
decorated function and class was changed to the position of the first 
decorator. It was made to help inspect.getsource() for functions to include 
decorator lines in the result. But the position of `def` and `class` lines was 
lost.

--
nosy: +christian.heimes, georg.brandl

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

Seems PR 9731 fixes this issue. I'll add tests later.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Change by Serhiy Storchaka :


--
keywords: +patch
pull_requests: +9117
stage:  -> patch review

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ned Batchelder]

Ned Batchelder  added the comment:

This is the --trace output for some stacked decorators:

$ cat -n /tmp/decdec.py
 1  def decorator1(f):
 2  return f
 3
 4  def decorator2(f):
 5  return f
 6
 7  def decorator3(f):
 8  return f
 9
10  @decorator1
11  @decorator2
12  @decorator3
13  def func():
14  print("hello")
15
16  func()

$ python3.7 -m trace --trace /tmp/decdec.py
 --- modulename: decdec, funcname: 
decdec.py(1): def decorator1(f):
decdec.py(4): def decorator2(f):
decdec.py(7): def decorator3(f):
decdec.py(10): @decorator1
decdec.py(11): @decorator2
decdec.py(12): @decorator3
 --- modulename: decdec, funcname: decorator3
decdec.py(8): return f
 --- modulename: decdec, funcname: decorator2
decdec.py(5): return f
 --- modulename: decdec, funcname: decorator1
decdec.py(2): return f
decdec.py(16): func()
 --- modulename: decdec, funcname: func
decdec.py(14): print("hello")
hello

$ python3.8 -m trace --trace /tmp/decdec.py
 --- modulename: decdec, funcname: 
decdec.py(1): def decorator1(f):
decdec.py(4): def decorator2(f):
decdec.py(7): def decorator3(f):
decdec.py(10): @decorator1
decdec.py(11): @decorator2
decdec.py(12): @decorator3
decdec.py(10): @decorator1
 --- modulename: decdec, funcname: decorator3
decdec.py(8): return f
 --- modulename: decdec, funcname: decorator2
decdec.py(5): return f
 --- modulename: decdec, funcname: decorator1
decdec.py(2): return f
decdec.py(16): func()
 --- modulename: decdec, funcname: func
decdec.py(14): print("hello")
hello


In Python3.8, "@decorator1" appears twice, as both the first and the last 
decorator line traced.  There's no conceptual reason to show that line twice.

I'd like to consider the stacked decorator case separately from the multi-line 
function call case.  Yes, they are consequences of the same change.  One change 
can have good effects and bad effects.  We can do further work to eliminate the 
bad effects.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Terry J. Reedy]

Terry J. Reedy  added the comment:

I have never looked at the trace of a decorated object before.  The 3.7 
behavior treating the inner decorator line as the first line of the decorated 
function definition looks wrong to me.  I actually expected the line pointer to 
move down to the def line, analogously to the following, at least until after 
MAKE_FUNCTION, but moving to the beginning of the statement for the rest would 
seem proper.

>>> dis.dis("""a = f(
f(
f(
3)))""")
  1   0 LOAD_NAME0 (f)

  2   2 LOAD_NAME0 (f)

  3   4 LOAD_NAME0 (f)

  4   6 LOAD_CONST   0 (3)
  8 CALL_FUNCTION1
 10 CALL_FUNCTION1
 12 CALL_FUNCTION1
 14 STORE_NAME   1 (a)
 16 LOAD_CONST   1 (None)
 18 RETURN_VALUE

--
nosy: +terry.reedy

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

First the decorator itself is loaded. Then the function is created, decorators 
are called and the result is bound to the name.

There is similar situation in the case of multiline call.

$ cat -n multiline_call.py 
 1  def f(a, b):
 2  return [
 3  a,
 4  b,
 5  ]
 6
 7  x = f(
 8  1,
 9  2,
10  )

$ ./python -m trace --trace multiline_call.py

In 3.7:

 --- modulename: multiline_call, funcname: 
multiline_call.py(1): def f(a, b):
multiline_call.py(7): x = f(
multiline_call.py(8): 1,
multiline_call.py(9): 2,
 --- modulename: multiline_call, funcname: f
multiline_call.py(3): a,
multiline_call.py(4): b,

In 3.8:

 --- modulename: multiline_call, funcname: 
multiline_call.py(1): def f(a, b):
multiline_call.py(7): x = f(
multiline_call.py(8): 1,
multiline_call.py(9): 2,
multiline_call.py(7): x = f(
 --- modulename: multiline_call, funcname: f
multiline_call.py(3): a,
multiline_call.py(4): b,
multiline_call.py(2): return [

Line 7 started the execution with loading the function f. Then arguments are 
evaluated on lines 1 and 2. Then line 7 continue the execution with calling the 
function and consuming its result.

Maybe using a range of lines instead of a single line will help (as was 
discussed in issue12458). First time the single line with a decorator is 
executed, second time the multiline expression that starts with the same line 
is executed. But this may require a significant change of AST and bytecode 
format.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ned Batchelder]

Ned Batchelder  added the comment:

Yes, I agree that the assignment statement behavior is fine.  The stacked 
decorator behavior is not.

I understand that under the hood the two cases are very similar, but the syntax 
is different.  Jumping back to the first decorator makes it look like the 
decorators are executed in order and then the first decorator runs again.  
There is nothing in the syntax that makes revisting the first decorator line 
reasonable.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

I think this is a correct behavior.

$ cat -n multiline_assignment.py 
 1  x = 1
 2  y = 2
 3  z = [
 4  x,
 5  y,
 6  ]

$ ./python -m trace --trace multiline_assignment.py

In 3.7 the line with the assignment is missed:

 --- modulename: multiline_assignment, funcname: 
multiline_assignment.py(1): x = 1
multiline_assignment.py(2): y = 2
multiline_assignment.py(4): x,
multiline_assignment.py(5): y,

In 3.8:

 --- modulename: multiline_assignment, funcname: 
multiline_assignment.py(1): x = 1
multiline_assignment.py(2): y = 2
multiline_assignment.py(4): x,
multiline_assignment.py(5): y,
multiline_assignment.py(3): z = [

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ned Batchelder]

Ned Batchelder  added the comment:

Are we sure this is the behavior we want? Now when I step through your code in 
the debugger, it will show me line 2, then 3, then 4, then 2 again.

I can see the appeal for a multiline assignment statement, but for stacked 
decorators it just seems wrong.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

On other hand, consider the following example of multiline assignment:

$ rlwrap ./python -m dis
a = [
x,
y,
]

In 3.7:

  2   0 LOAD_NAME0 (x)

  3   2 LOAD_NAME1 (y)
  4 BUILD_LIST   2
  6 STORE_NAME   2 (a)
  8 LOAD_CONST   0 (None)
 10 RETURN_VALUE

In 3.8:

  2   0 LOAD_NAME0 (x)

  3   2 LOAD_NAME1 (y)

  1   4 BUILD_LIST   2
  6 STORE_NAME   2 (a)
  8 LOAD_CONST   0 (None)
 10 RETURN_VALUE

In 3.7 the line of the assignment "a = [" is not traced. In 3.8 it is traced.

These all are a consequences of the same change.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Serhiy Storchaka]

Serhiy Storchaka  added the comment:

This is because the first line of the function definition was the line of the 
last decorator in 3.7, and it is the line of the first decorator in 3.8.

$ rlwrap ./python -m dis

@decorator
@decorator
@decorator
def func():
pass

In 3.7:

  2   0 LOAD_NAME0 (decorator)

  3   2 LOAD_NAME0 (decorator)

  4   4 LOAD_NAME0 (decorator)
  6 LOAD_CONST   0 (", line 2>)
  8 LOAD_CONST   1 ('func')
 10 MAKE_FUNCTION0
 12 CALL_FUNCTION1
 14 CALL_FUNCTION1
 16 CALL_FUNCTION1
 18 STORE_NAME   1 (func)
 20 LOAD_CONST   2 (None)
 22 RETURN_VALUE

In 3.8:

  2   0 LOAD_NAME0 (decorator)

  3   2 LOAD_NAME0 (decorator)

  4   4 LOAD_NAME0 (decorator)

  2   6 LOAD_CONST   0 (", line 2>)
  8 LOAD_CONST   1 ('func')
 10 MAKE_FUNCTION0
 12 CALL_FUNCTION1
 14 CALL_FUNCTION1
 16 CALL_FUNCTION1
 18 STORE_NAME   1 (func)
 20 LOAD_CONST   2 (None)
 22 RETURN_VALUE

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ammar Askar]

Ammar Askar  added the comment:

It looks like this is caused by 
https://github.com/python/cpython/commit/da8d72c953369b872a12c13f136ada77a786714a

Adding Serhiy to the nosy list.

--
nosy: +ammar2, serhiy.storchaka

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue34876] Python3.8 changes how decorators are traced

[Ned Batchelder]

New submission from Ned Batchelder :

When decorating a function, the sequence of lines reported to the trace 
function is different in Python3.8 than with previous versions

$ cat -n decorator.py
 1  def decorator(f):
 2  return f
 3
 4  def f():
 5  @decorator
 6  @decorator
 7  @decorator
 8  def func():
 9  pass
10
11  import sys
12  def trace(frame, event, args):
13  print(frame.f_lineno, event)
14  return trace
15
16  sys.settrace(trace)
17  f()

$ python3.7 decorator.py
4 call
5 line
6 line
7 line
1 call
2 line
2 return
1 call
2 line
2 return
1 call
2 line
2 return
7 return

$ python3.8 decorator.py
4 call
5 line
6 line
7 line
5 line
1 call
2 line
2 return
1 call
2 line
2 return
1 call
2 line
2 return
5 return

Is this intentional? Will it be changed back before 3.8 ships?

People are testing their projects against 3.8-dev, and reporting problems with 
coverage.  The problems are due to these sorts of changes.

--
components: Interpreter Core
messages: 326921
nosy: nedbat
priority: normal
severity: normal
status: open
title: Python3.8 changes how decorators are traced
versions: Python 3.8

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com