classification
Title: traceback: errors in the linecache module at exit
Type: behavior Stage:
Components: Library (Lib) Versions: Python 3.5, Python 3.4
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: haypo Nosy List: haypo, martin.panter, pitrou, python-dev, serhiy.storchaka
Priority: normal Keywords: patch

Created on 2014-10-10 11:36 by haypo, last changed 2014-12-05 09:27 by haypo. This issue is now closed.

Files
File name Uploaded Description Edit
destructortest.py haypo, 2014-10-10 11:36
traceback_ignore_linecache_error.patch haypo, 2014-10-10 11:51 review
traceback_at_exit.patch haypo, 2014-10-12 23:07 review
traceback_at_exit-2.patch haypo, 2014-10-14 22:48 review
Messages (20)
msg228986 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-10 11:36
Attached destructortest.py script comes the issue #22480. It calls traceback.print_exception() at exit. The problem is that the call occurs late during Python finalization. The object was stored in the namespace of the main module. Currently, Python deletes builtin functions and then deletes modules (in a random order?).

Since the traceback module is used to display errors, it's annoying to get errors in the traceback module :-) I see two options to fix the specific issue of destructortest.py:

* Ignore exceptions while calling linecache
* Detect Python finalization and don't try to use the linecache module in this case

Attached patch implements the second option. I'm not sure that it's the best one. It includes an unit test.

Depending on the option, we can fix the issue only in Python 3.5, or fix Python 2.7, 3.4 and 3.5.

Current output:
---
Traceback (most recent call last):
Exception ignored in: <bound method PrintExceptionAtExit.__del__ of <__main__.PrintExceptionAtExit object at 0x7f70b84ac878>>
Traceback (most recent call last):
  File "destructortest.py", line 15, in __del__
  File "/home/haypo/prog/python/default/Lib/traceback.py", line 169, in print_exception
  File "/home/haypo/prog/python/default/Lib/traceback.py", line 153, in _format_exception_iter
  File "/home/haypo/prog/python/default/Lib/traceback.py", line 18, in _format_list_iter
  File "/home/haypo/prog/python/default/Lib/traceback.py", line 65, in _extract_tb_or_stack_iter
  File "/home/haypo/prog/python/default/Lib/linecache.py", line 15, in getline
  File "/home/haypo/prog/python/default/Lib/linecache.py", line 41, in getlines
  File "/home/haypo/prog/python/default/Lib/linecache.py", line 126, in updatecache
  File "/home/haypo/prog/python/default/Lib/tokenize.py", line 438, in open
AttributeError: module 'builtins' has no attribute 'open'
---

Expected output:
---
Traceback (most recent call last):
  File "destructortest.py", line 7, in __init__
ZeroDivisionError: division by zero
---
msg228990 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-10 11:40
Errors in the traceback module (caused by linecache) are common when working on the asyncio module in debug mode. The asyncio tries to log exceptions at exit to help the debug to track bugs. It uses the garbage collector and destructors on objects. Example of debug tool:
https://docs.python.org/dev/library/asyncio-dev.html#detect-exceptions-never-consumed

See for examples issues #22428 and #22480.
msg228991 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-10-10 11:46
There is no patch.
msg228992 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-10 11:51
> There is no patch.

Oh no :-( I revert all my local changes and I forgot to produce the patch... My change added a new sys._is_finalizing() function which exposes the private C variable "_Py_Finalizing".

Well, here is a patch which implements the first option (ignore linecache errors).
msg229004 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2014-10-10 14:57
Alternative solution of this issue would be to use "from builtins import open as _open" instead of "import builtins".
msg229012 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-10 15:42
See also the issue #19421.
msg229203 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-12 23:07
> Alternative solution of this issue would be to use "from builtins import open as _open" instead of "import builtins".

Right. I prefer your solution because it's much simpler, it doesn't make traceback less usable at exit, and it doesn't need to make assumption on the Python status.

Here is a patch implementing this idea with an unit test.
msg229230 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2014-10-13 07:43
There is one downside of my solution. For now the code uses current builtin open() which can be overloaded (to handle reading from ZIP archive for example, or to check permissions). With my solution it uses builtin open() at the time of import. I don't know insofar current behavior is intentional. We should take a decision of yet one core developer.
msg229365 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-14 22:48
> There is one downside of my solution. For now the code uses current builtin open() which can be overloaded (to handle reading from ZIP archive for example, or to check permissions).

Oh, does anyone really modify the builtin open() for that? If you already monkey-patch Python builtin, you are probably able to monkey-patch also tokenize._builtin_open.

I don't think that monkey-patching builtins is promoted nor well supported. They are probably other places where a local references to builtins functions are kept.

The importlib module provides the get_source() function which is the best way to retrieve the source code from any kind of module, including ZIP files. But tokenize.open() really expects a clear text ".py" file.


> With my solution it uses builtin open() at the time of import.

I don't see how your solution is different than mine.

But your solution is probably enough to tokenize needs (it only requires the builtin open funciton) and it's shorter.


> I don't know insofar current behavior is intentional. We should take a decision of yet one core developer.

Since I wrote tokenize.open(), I can explain why I chose to import builtins :-) It's just one option to handle two functions with the same name: (builtins.)open and (tokenize.)open.

"_open = open" is another common option to handle this issue.
msg229366 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-14 22:48
traceback_at_exit-2.patch: Updated patch to remove "import builtins" from tokenize.py, it's no more needed.
msg229807 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-22 10:21
> traceback_at_exit-2.patch: Updated patch to remove "import builtins" from tokenize.py, it's no more needed.

Antoine, Serhiy: What do you think about this patch?

IMO the bug is very simple and fixes a common bug.
msg229811 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2014-10-22 11:04
The patch looks fragile to me: who knows whether other similar problems can appear in other situations?

I would prefer something like traceback_ignore_linecache_error.patch, perhaps combined with a new function that would tell you whether the interpreter is shutting down.
msg229813 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2014-10-22 12:08
> Since I wrote tokenize.open(), I can explain why I chose to import builtins :-)

Then it is good to me.

> I would prefer something like traceback_ignore_linecache_error.patch, perhaps combined with a new function that would tell you whether the interpreter is shutting down.

I think we can apply both solutions. Keeping a reference to open will make traceback more usable at exit and ignoring exception will make it more robust in worst case.

And I support the idea about public function or attribute that would tell you whether the interpreter is shutting down. This would be useful in many modules. But this is different issue.
msg229815 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-22 12:16
> The patch looks fragile to me: who knows whether other similar problems can appear in other situations?

Maybe we can always ignore non fatal errors when calling linecache
from print_exception? Having the Python source code in the traceback
is better, but it's easy to get it because the filename and line
number is always present.

Maybe the linecache module can provide a better exception than the
current AttributeError?
msg229816 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-22 12:16
> The patch looks fragile to me: who knows whether other similar problems can appear in other situations?

Oh, I forgot to say that yes, my patch is incomplete, but it is simple
and it is already make the code more reliable.
msg229819 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-10-22 12:32
Oh, I see that Antoine opened the issue #22696.
msg232168 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-12-05 00:51
Can I apply traceback_at_exit-2.patch? I know that my change on tokenize is not perfect, but it doesn't look like an hack, and it adds a new unit test.

The linecache module can be enhanced in the issue #22696.
msg232177 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2014-12-05 07:41
Yes, please do this.
msg232183 - (view) Author: Roundup Robot (python-dev) Date: 2014-12-05 09:25
New changeset cd3244416592 by Victor Stinner in branch '3.4':
Issue #22599: Enhance tokenize.open() to be able to call it during Python
https://hg.python.org/cpython/rev/cd3244416592

New changeset 22f2784a276e by Victor Stinner in branch 'default':
(Merge 3.4) Issue #22599: Enhance tokenize.open() to be able to call it during
https://hg.python.org/cpython/rev/22f2784a276e
msg232185 - (view) Author: STINNER Victor (haypo) * (Python committer) Date: 2014-12-05 09:27
> Yes, please do this.

Ok done. I only added the test to default, not in the 3.4 branch. As Antoine noticed, the test is fragile, I perfer to not backport it.

Ok, let's focus now on the issue #22696 ;-)
History
Date User Action Args
2014-12-05 09:27:35hayposetstatus: open -> closed
resolution: fixed
dependencies: - Add a function to know about interpreter shutdown
messages: + msg232185
2014-12-05 09:25:49python-devsetnosy: + python-dev
messages: + msg232183
2014-12-05 07:41:57serhiy.storchakasetmessages: + msg232177
versions: + Python 3.4
2014-12-05 00:51:34hayposetmessages: + msg232168
2014-11-16 14:45:37serhiy.storchakasetassignee: haypo
dependencies: + Add a function to know about interpreter shutdown
type: behavior
2014-10-22 12:32:33hayposetmessages: + msg229819
2014-10-22 12:16:59hayposetmessages: + msg229816
2014-10-22 12:16:03hayposetmessages: + msg229815
2014-10-22 12:08:20serhiy.storchakasetmessages: + msg229813
2014-10-22 11:04:29pitrousetmessages: + msg229811
2014-10-22 10:21:58hayposetmessages: + msg229807
2014-10-14 22:48:53hayposetfiles: + traceback_at_exit-2.patch

messages: + msg229366
2014-10-14 22:48:25hayposetmessages: + msg229365
2014-10-13 07:43:23serhiy.storchakasetmessages: + msg229230
2014-10-12 23:07:42hayposetfiles: + traceback_at_exit.patch

messages: + msg229203
2014-10-10 15:42:38hayposetmessages: + msg229012
2014-10-10 14:57:34serhiy.storchakasetnosy: + serhiy.storchaka
messages: + msg229004
2014-10-10 13:42:56martin.pantersetnosy: + martin.panter
2014-10-10 11:51:49hayposetfiles: + traceback_ignore_linecache_error.patch
keywords: + patch
messages: + msg228992
2014-10-10 11:46:55pitrousetnosy: + pitrou
messages: + msg228991
2014-10-10 11:40:07hayposetmessages: + msg228990
2014-10-10 11:36:01haypocreate