I can reproduce this here. In that test, I added the following:
with open('/tmp/debug', 'w') as f:
for call in self.stderr.method_calls:
f.write('call: %s\n' % str(call))
This gives:
=========== 8< ============
call: call.write('Python <MagicMock name=\'sys.version\' id=\'140431558254320\'> on <MagicMock name=\'sys.platform\' id=\'140431558262512\'>\nType "help", "copyright", "credits" or "license" for more information.\n(InteractiveConsole)\n')
call: call.write('Traceback (most recent call last):\n')
call: call.write(' File "/usr/lib/python3.4/code.py", line 90, in runcode\n')
call: call.write(' ')
call: call.write('exec(code, self.locals)')
call: call.write('\n')
call: call.write(' File "<console>", line 1, in <module>\n')
call: call.write('NameError')
call: call.write(': ')
call: call.write("name 'undefined' is not defined")
call: call.write('\n')
call: call.write('\n')
=========== 8< ============
Observe that the test checks
if 'NameError:' in ''.join(call[1]):
but the "NameError" and the ":" are in two different call lines. I don't know how self.stderr.method_calls is built, but this sounds like a race condition/timing or a stdin/out buffering issue? I. e. the original print that produces the "NameError:" certainly does that in two steps; perhaps the testsuite thing that repeatedly read()s on stderr catches these two as separate write()s then? |