classification
Title: Error on leaving IDLE with quit() or exit() under Linux
Type: behavior Stage: resolved
Components: IDLE Versions: Python 3.4, Python 3.3, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: 13495 Superseder:
Assigned To: roger.serwy Nosy List: Boris.FELD, Raj, ajaksu2, gerluijten, gpolo, python-dev, roger.serwy, srid, terry.reedy
Priority: normal Keywords: patch

Created on 2009-03-15 12:44 by gerluijten, last changed 2013-06-12 03:14 by roger.serwy. This issue is now closed.

Files
File name Uploaded Description Edit
issue5492.patch roger.serwy, 2011-12-22 19:19 review
issue5492_rev1.patch roger.serwy, 2013-04-20 02:10 review
Messages (18)
msg83629 - (view) Author: Ger Luijten (gerluijten) Date: 2009-03-15 12:44
Hello developers,

Found a small error when using IDLE Version 3.1a1 under Kubuntu Linux
8.10 in the terminal.
Kubuntu is fully updated and no installation errors for Python 3.1a1.

See the listing from my installation notes below.

Greetings, Ger


Let's see if IDLE works, by starting it in the terminal:
$ idle

IDLE works in the new Python version 3.1a1, but there is an error!

When leaving IDLE with quit() or exit() and clicking the OK button for
the question 'The program is still running! Do you want to kill it?
there's the errors listed below, that does not occur when leaving IDLE
with Ctrl-D instead of quit():

Error when leaving with quit() (Full error listing)
*** Internal Error: rpc.py:SocketIO.localcall()

 Object: stderr
 Method: <bound method PseudoFile.write of <idlelib.PyShell.PseudoFile
object at 0x9ce942c>>
 Args: ('Traceback (most recent call last):',)

Traceback (most recent call last):
  File "/usr/local/lib/python3.1/idlelib/rpc.py", line 188, in localcall
    ret = method(*args, **kwargs)
  File "/usr/local/lib/python3.1/idlelib/PyShell.py", line 1218, in write
    self.shell.write(s, self.tags)
  File "/usr/local/lib/python3.1/idlelib/PyShell.py", line 1201, in write
    self.text.mark_gravity("iomark", "left")
AttributeError: 'NoneType' object has no attribute 'mark_gravity'

Error when leaving with exit() (Partial error listing: only the error
part that difffers is listed here)
 Object: stderr
 Method: <bound method PseudoFile.write of <idlelib.PyShell.PseudoFile
object at 0xa08642c>>
 Args: ('  File "<pyshell#0>", line 1, in <module>\n',)
msg86624 - (view) Author: Daniel Diniz (ajaksu2) Date: 2009-04-26 22:21
Cannot confirm on Kubuntu 8.04, Python 3.1a2+ built from source,
tkinter.TkVersion is 8.5.
msg89368 - (view) Author: Guilherme Polo (gpolo) * (Python committer) Date: 2009-06-14 20:22
I can get a similar error from time to time, just try it a couple of
times and I believe you should hit it too.

When that error isn't thrown IDLE prints the traceback of a SystemExit
exception inside IDLE right before closing, so it may be hard to notice.

The error I am able to get (using 3.1rc2+ r73431):


*** Internal Error: rpc.py:SocketIO.localcall()

 Object: stderr 
 Method: <bound method PseudoFile.write of <idlelib.PyShell.PseudoFile
object at 0x8b6084c>> 
 Args: ('SystemExit: None\n',)

Traceback (most recent call last):
  File "/home/gpolo/python-dev/py3k/Lib/idlelib/rpc.py", line 188, in
localcall
    ret = method(*args, **kwargs)
  File "/home/gpolo/python-dev/py3k/Lib/idlelib/PyShell.py", line 1231,
in write
    self.shell.write(s, self.tags)
  File "/home/gpolo/python-dev/py3k/Lib/idlelib/PyShell.py", line 1214,
in write
    self.text.mark_gravity("iomark", "left")
AttributeError: 'NoneType' object has no attribute 'mark_gravity'


I'm not sure if it can't happen in python-trunk too, I see it throws an
exception when leaving IDLE but till now I never got an error message
after IDLE (almost) exited.
msg149708 - (view) Author: Boris FELD (Boris.FELD) * Date: 2011-12-17 21:53
The problem still exists in trunk with 3.2 and 3.3.
msg149790 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2011-12-18 18:24
You can trigger this error every time if you change ".after(2*self.poll_interval, self.close2)" to ".after(1, self.close2)" in PyShell.py
msg150106 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2011-12-22 19:19
The attached patch fixes the problem. The close method does not need to wait for poll_subprocess rescheduling to stop. The subprocess will be killed, which would cause the socket to timeout. With closing=True, poll_subprocess will return and not reschedule.
msg185603 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2013-03-31 00:52
I am presuming 2.7 has same problem since it has same code.

The patch appears to give PyShell.close a return value it did not have before. Perhaps remove the return?

I am slightly puzzled: self.pollinterval is 50 (millisecs). If reducing the wait from 100 to 1 makes the problem constant, why does reducing it to 0 make it go away? What have I misunderstood?

Trying to test on Windows in a 3.3 build, I get the following with or without the patch:

>>> exit()
Traceback (most recent call last):
  File "<pyshell#1>", line 1, in <module>
    exit()
  File "D:\Python\dev\py33\lib\site.py", line 380, in __call__
    raise SystemExit(code)
SystemExit: None
--------------------------------
def __call__(self, code=None):
            # Shells like IDLE catch the SystemExit, but listen when
            # stdin wrapper is closed.
            try:
                fd = -1
                if hasattr(sys.stdin, "fileno"):
                    fd = sys.stdin.fileno()
                if fd != 0:
                    # Don't close stdin if it wraps fd 0
                    sys.stdin.close()
            except:
                pass
            raise SystemExit(code)
>>>
---------------------------
<bare excepts are evil>
----------------------------
>>> import sys
>>> hasattr(sys.stdin, "fileno")
True
>>> sys.stdin.fileno
<built-in method fileno of PseudoInputFile object at 0x02893C08>
>>> sys.stdin.fileno()
Traceback (most recent call last):
  File "<pyshell#3>", line 1, in <module>
    sys.stdin.fileno()
io.UnsupportedOperation: fileno

The problem is that PseudoInputFile subclasses PseudoFile which now subclasses TestIOBase without overriding .fileno(), which raises the above. This is from #9290.

Bottom line: I believe quit() and exit() are broken in the current 2.7, 3.2, and 3.3 rc's. I will report a possible quick fix on pydev.
msg185605 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2013-03-31 02:07
After reading the doc for IOBase.fileno: "Return the underlying file descriptor (an integer) of the stream if it exists. An OSError is raised if the IO object does not use a file descriptor." I decided that the bug is in the assumptions made by site.py.
msg185694 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-03-31 23:22
I found the root cause of the original error. 

Entering "exit()" at the shell raises SystemExit which gets written to the shell's text widget. The call to actually write the text passes through .write() in Lib/idlelib/OutputWindow.py, which calls text.update(). The call to .update() enters the Tk event loop and flushes pending events, including expired .after callbacks. 

Forcing the .after callback in .close() to 1 ms will always trigger the error. Commenting out the text.update() in OutputWindow.py avoids the error.

The patch causes .kill_subprocess() to execute immediately which prevents the subprocess from writing to sys.stderr.
msg187180 - (view) Author: Ger Luijten (gerluijten) Date: 2013-04-17 16:50
Hello Roger,

To you and others that worked on this bug a big thanks for the extra deep
dig into the chain of events to find this old bug and fix it. Impressive!

Because I'm not familiar with the inner workings that cause this bug I was
wondering if the kill command you use is the structural solution or just a
clever workarond to prevent the error being written to the text widget and
forcing the program to stop abruptly.

For me your explanation raised the question if other processes that should
terminate normally are now prevented from doing so and for instance are not
able to do clear allocated memory (garbage collection).

Could you shed some light on your bug fix?

Greetings, Ger

2013/4/1 Roger Serwy <report@bugs.python.org>

>
> Roger Serwy added the comment:
>
> I found the root cause of the original error.
>
> Entering "exit()" at the shell raises SystemExit which gets written to the
> shell's text widget. The call to actually write the text passes through
> .write() in Lib/idlelib/OutputWindow.py, which calls text.update(). The
> call to .update() enters the Tk event loop and flushes pending events,
> including expired .after callbacks.
>
> Forcing the .after callback in .close() to 1 ms will always trigger the
> error. Commenting out the text.update() in OutputWindow.py avoids the error.
>
> The patch causes .kill_subprocess() to execute immediately which prevents
> the subprocess from writing to sys.stderr.
>
> ----------
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue5492>
> _______________________________________
>
msg187225 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-04-18 05:48
Hello Ger,

Sure, I can explain. IDLE is driven by the Tk event loop. Calls to .update() flushes all pending events and expired .after callbacks. 

When close() gets called in PyShell, it places the finalization of the close (using close2()) into the Tk event queue as a .after callback. Now, when the error message arrives over RPC to the PyShell, it is written to the .text widget using the write() method. Here's a snippet from PyShell.py:

            self.text.mark_gravity("iomark", "right")
            count = OutputWindow.write(self, s, tags, "iomark")
            self.text.mark_gravity("iomark", "left")

The OutputWindow.write() command eventually calls .update() before returning. That .update() call may flush the close2() callback if the timer expired. If so, then .text gets set to None. The next line to restore the gravity to the left is doing an attribute lookup for "mark_gravity" on None which causes the error.

I hope that clarifies why the patch works.

Can someone verify that the patch works? I've managed to convince myself of its validity, but it is always good to get another set of eyes on it in case I missed something.
msg187323 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2013-04-19 00:42
3.4 fresh build, Win 7:
^z now disabled, as apparently intended.

Without the patch ^d or window close button [x] quits Idle cleanly.
>>> import idlelib.idle  # ^D or [X] in Idle
>>>

With the patch, Idle disappears but console displays error messages. This is an unacceptible regression; something is not right. Sorry ;-).
>>> import idlelib.idle  # ^D in idle
>>> invalid command name "53165560callit"
    while executing
"53165560callit"
    ("after" script)
invalid command name "51796472callit"
    while executing
"51796472callit"
    ("after" script)

>>> import idlelib.idle  # [X] in Idle
>>> invalid command name "52980280callit"
    while executing
"52980280callit"
    ("after" script)


Without or with patch, quit() or exit brings up TK box
(?) The program is still running!
    Do you want to kill it?
    [OK]  [Cancel]
Did this always happen?

[Cancel] causes traceback (not good, regression?)
Traceback (most recent call last):
  File "<pyshell#0>", line 1, in <module>
    quit()
  File "D:\Python\dev\cpython\lib\site.py", line 356, in __call__
    raise SystemExit(code)
SystemExit: None

[OK] gives clean exit
>>> import idlelib.idle  # quit(), [ok] in idle
>>> 

Same with 3.3 with from download from repository but without fresh python build (as pcbuild fails).
msg187394 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-04-20 02:10
Good catch Terry! I've been testing using "python -m idlelib.idle" instead of importing it from an interactive prompt. I'll need to remember to consider that test vector in the future.

I figured out why those messages are popping up. The Tk event loop remains running when in the interactive Python REPL due to a PyOS_InputHook driving the Tk loop periodically. Some .after callbacks expire and Tcl tries calling into a Python function that no longer exists. The ColorDelegator's recolorize() and PyShell's poll_subprocess() are the callbacks. (Adding a "print(name, func)" to the after() function in Lib/tkinter/__init__.py revealed the link between the Tcl reference name and the Python reference name.)

The extra ColorDelegator call is actually a bug, related to #13495. (I need to expand it that issue to include this new problem.) Two ColorDelegators get loaded, and only one gets its close() method called which properly cancels the .after callback into recolorize. The "orphaned" ColorDelegator still exists in the delegator chain with an active .after callback.

Once both those .after callbacks are canceled, then the error messages Terry sees are no longer shown.

The rev1 patch includes extra code to handle cancellation of the poll_subprocess .after callback. I'll be posting the multi-color delegator fix to #13495.
msg188350 - (view) Author: Ger Luijten (gerluijten) Date: 2013-05-04 10:34
Hello Roger,

Thanks for the clear explanation!

Greetings, Ger

2013/4/20 Roger Serwy <report@bugs.python.org>

>
> Roger Serwy added the comment:
>
> Good catch Terry! I've been testing using "python -m idlelib.idle" instead
> of importing it from an interactive prompt. I'll need to remember to
> consider that test vector in the future.
>
> I figured out why those messages are popping up. The Tk event loop remains
> running when in the interactive Python REPL due to a PyOS_InputHook driving
> the Tk loop periodically. Some .after callbacks expire and Tcl tries
> calling into a Python function that no longer exists. The ColorDelegator's
> recolorize() and PyShell's poll_subprocess() are the callbacks. (Adding a
> "print(name, func)" to the after() function in Lib/tkinter/__init__.py
> revealed the link between the Tcl reference name and the Python reference
> name.)
>
> The extra ColorDelegator call is actually a bug, related to #13495. (I
> need to expand it that issue to include this new problem.) Two
> ColorDelegators get loaded, and only one gets its close() method called
> which properly cancels the .after callback into recolorize. The "orphaned"
> ColorDelegator still exists in the delegator chain with an active .after
> callback.
>
> Once both those .after callbacks are canceled, then the error messages
> Terry sees are no longer shown.
>
> The rev1 patch includes extra code to handle cancellation of the
> poll_subprocess .after callback. I'll be posting the multi-color delegator
> fix to #13495.
>
> ----------
> dependencies: +IDLE: Regressions - Two ColorDelegator instances loaded and
> -e no longer edits new files.
> Added file: http://bugs.python.org/file29945/issue5492_rev1.patch
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue5492>
> _______________________________________
>
msg188490 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-05-06 04:26
Terry, the SystemExit traceback from clicking cancel is expected given how Lib/site.py's Quitter first closes sys.stdin and then raises SystemExit. Closing sys.stdin causes the dialog, the raised exception just gets printed.

We could change the behavior such that when IDLE's internals catch SystemExit, then the close dialog appears. This avoids having to rely on closing sys.stdin to signal IDLE to close. See issue17838 for the patch to do just that.

(It looks like #17838, #17585, and this issue are converging.)
msg191004 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-06-12 03:06
I noticed that the tracebacks didn't occur in 2.7 due to 872a3aca2120, but that patch was not grafted onto the 3.x branches. I'll take care of that.

With #13495 fixed, the two errors mentioned in msg187323 do not occur with the _rev1 patch applied.
msg191005 - (view) Author: Roundup Robot (python-dev) Date: 2013-06-12 03:13
New changeset ca8e86711403 by Roger Serwy in branch '2.7':
#5492: Avoid traceback when exiting IDLE caused by a race condition.
http://hg.python.org/cpython/rev/ca8e86711403

New changeset da852f5250af by Roger Serwy in branch '3.3':
#5492: Avoid traceback when exiting IDLE caused by a race condition.
http://hg.python.org/cpython/rev/da852f5250af

New changeset 187da33826eb by Roger Serwy in branch 'default':
#5492: merge with 3.3
http://hg.python.org/cpython/rev/187da33826eb
msg191006 - (view) Author: Roger Serwy (roger.serwy) * (Python committer) Date: 2013-06-12 03:14
This issue is now fixed. Thank you everyone for helping!
History
Date User Action Args
2013-06-12 03:14:44roger.serwysetstatus: open -> closed
resolution: fixed
messages: + msg191006

stage: patch review -> resolved
2013-06-12 03:13:36python-devsetnosy: + python-dev
messages: + msg191005
2013-06-12 03:06:41roger.serwysetmessages: + msg191004
2013-05-08 02:25:49Rajsetnosy: + Raj
2013-05-06 04:26:45roger.serwysetmessages: + msg188490
2013-05-04 10:34:40gerluijtensetmessages: + msg188350
2013-04-20 02:10:49roger.serwysetfiles: + issue5492_rev1.patch

dependencies: + IDLE: Regressions - Two ColorDelegator instances loaded
messages: + msg187394
2013-04-19 00:42:24terry.reedysetmessages: + msg187323
2013-04-18 05:48:21roger.serwysetassignee: roger.serwy
messages: + msg187225
stage: test needed -> patch review
2013-04-17 16:50:53gerluijtensetmessages: + msg187180
2013-03-31 23:22:08roger.serwysetmessages: + msg185694
2013-03-31 02:07:25terry.reedysetmessages: + msg185605
2013-03-31 00:52:18terry.reedysetnosy: + terry.reedy

messages: + msg185603
versions: + Python 2.7, Python 3.4, - Python 3.1, Python 3.2
2011-12-22 19:19:26roger.serwysetfiles: + issue5492.patch
keywords: + patch
messages: + msg150106
2011-12-18 18:24:26roger.serwysetnosy: + roger.serwy
messages: + msg149790
2011-12-17 21:53:01Boris.FELDsetnosy: + Boris.FELD

messages: + msg149708
versions: + Python 3.2, Python 3.3
2010-02-10 18:09:17sridsetnosy: + srid
2009-06-14 20:22:11gpolosetmessages: + msg89368
2009-04-26 22:21:15ajaksu2setpriority: normal

nosy: + ajaksu2, gpolo
messages: + msg86624

type: crash -> behavior
stage: test needed
2009-03-15 12:44:36gerluijtencreate