Cannot capture sys.stderr output from an uncaught exception in a multiprocessing Process using a multiprocessing Queue

[pppery]

BPO	27081
Nosy	@pppery, @applio, @Vgr255
Files	issue27081.py: Cleaned and embellished example with commentary.

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = None
created_at = <Date 2016-05-21.21:04:33.243>
labels = ['type-bug', 'library']
title = 'Cannot capture sys.stderr output from an uncaught exception in a multiprocessing Process using a multiprocessing Queue'
updated_at = <Date 2016-07-03.04:25:20.887>
user = 'https://github.com/pppery'

bugs.python.org fields:

activity = <Date 2016-07-03.04:25:20.887>
actor = 'davin'
assignee = 'none'
closed = False
closed_date = None
closer = None
components = ['Library (Lib)']
creation = <Date 2016-05-21.21:04:33.243>
creator = 'ppperry'
dependencies = []
files = ['43613']
hgrepos = []
issue_num = 27081
keywords = []
message_count = 7.0
messages = ['266026', '266028', '269733', '269736', '269737', '269738', '269750']
nosy_count = 5.0
nosy_names = ['jnoller', 'sbt', 'ppperry', 'davin', 'abarry']
pr_nums = []
priority = 'normal'
resolution = None
stage = None
status = 'open'
superseder = None
type = 'behavior'
url = 'https://bugs.python.org/issue27081'
versions = ['Python 3.4']

[pppery]

In this code, one would expect that the entire traceback from the uncaught recursion error would get put onto the queue, where it could be read in the main process.
queue = multiprocessing.Queue()
def do_stderr(queue):
class f:
def write(self, data):
queue.put(data)
def flush(self):
pass
import sys
sys.stderr = f()
def g():
g()
g()
multiprocessing.Process(target=do_stderr,args=(queue,)).start()

However, only some of the output actually gets enqueued:

 Process IdleProcess-6:
 Traceback (most recent call last):
 File "C:\Python34\lib\multiprocessing\process.py", line 254, in _bootstrap
    self.run()
  File "C:\Python34\lib\multiprocessing\process.py", line 93, in run
    self._target(*self._args, **self._kwargs)
  File "<pyshell#446>", line 12, in do_stderr
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g
  File "<pyshell#446>", line 11, in g

The rest of the data is not accessible.

[pppery]

Replacing the first line with queue = multiprocessing.SimpleQueue() fixes this issue.

[applio]

I took the example snippet and cleaned things up a bit, adding some crude timestamping and commentary. (Attached)

In the example, when the Process finally dies, a lot of information has been put onto the Queue but it hasn't necessarily had enough time to be synced to the parent process so it may be only a truncated subset of the data that remains available/visible/retrievable on the parent. How much data gets synced to the parent depends on many factors and should even vary from one run to another.

That is to say that a multiprocessing.Queue is not going to hold up a dying process to finish communicating data to other processes.

[pppery]

I believe that regardless of the number of prints to sys.stderr that happen before the recursion error, all of them will get sent to the parent. The problem is that the queue is flushed before the uncaught error is sent to stderr, not after.

[Vgr255]

Worth of note: bpo-26823 will actually change printing to stderr for recursion errors (if/when it gets merged that is; I don't know what's holding it up). It might be interesting to see if you can still witness this issue with the patch applied.

[pppery]

This issue isn't specific to recursion errors. It only occurs when the error message is long enough, so bpo-26823 would fix the RecursionError case, but it would still happen when someone calls a function with a billion-character-long name that raises an error, for example.

[applio]

The spawned process (you appear to have run on Windows, so I'm assuming spawn but that's not so significant) has triggered an unhandled exception. If the triggering and subsequent sending of the traceback to stderr is synchronous and completes before Python actually kills the process, then the original "one would expect" statement would make sense. Removing the use of the Queue entirely and substituting the use of a socket to communicate from the child (spawned) process to some distinct listener process results in only a portion of the traceback text being received by the listener (or sometimes little to none of the traceback text). This suggests that the original premise is false and the expectation inaccurate.