[issue10207] test_file2k crashes under Windows

[David Bolen]

David Bolen <db3l.net at gmail.com> added the comment:

Can't really say why it's just hitting now more consistently but the failure is an internal CRT exception during a file close, when it is handed what appears to be an invalid FILE * (the internal structure has bad data).

I think it's more chance that it appears to be in the 86819-85819 change.  I've been able to generate the same error in 85816 with 4-5 test runs.  In all cases it's sporadic, but can trigger just by running test_file2k so doesn't require any other tests to have run.

With a local build and the VS debugger, the failure point is the CRT during an internal flush as part of fclose().  The FILE * structure looks like it became corrupted prior to that point.

The tail end of the failure traceback is:

msvcr90d.dll!_write_nolock(int fh=3, const void * buf=0x00f4e008, unsigned int cnt=1)  Line 322 + 0x6 bytes
msvcr90d.dll!_write(int fh=3, const void * buf=0x00f4e008, unsigned int cnt=1)  Line 75 + 0x11 bytes
msvcr90d.dll!_flush(_iobuf * str=0x10311448)  Line 154 + 0x1d bytes
msvcr90d.dll!_fclose_nolock(_iobuf * str=0x10311448)  Line 105 + 0x9 bytes
msvcr90d.dll!fclose(_iobuf * stream=0x10311448)  Line 57 + 0x9 bytes
python27_d.dll!close_the_file(PyFileObject * f=0x00bef5d8)  Line 451 + 0x7 bytes
python27_d.dll!file_close(PyFileObject * f=0x00bef5d8)  Line 651 + 0x9 bytes
python27_d.dll!call_function(_object * * * pp_stack=0x0145f228, int oparg=12514776)  Line 3996 + 0x10 bytes

The last Python runtime code is in the close_the_file frame (fileobject.c, line 451), it's the line:

    sts = (*local_close)(local_fp)

and local_fp has bad pointers inside its structure:

    local_fp    0x10311448      _iobuf *
                _ptr    0x00f4e009 <Bad Ptr>    char *
                _cnt    16383   int
                _base   0x00f4e008 <Bad Ptr>    char *
                _flag   34178   int
                _file   3       int
                _charbuf        0       int
                _bufsiz 16384   int
                _tmpfname       0x00000000 <Bad Ptr>    char *

I've also seem some cases where _ptr isn't explicitly flagged as a Bad Ptr (e.g., value 0x00e56031 with r85816) but is still invalid to access.

The local_close code runs outside the GIL, so maybe some sort of race condition with the parent Python file object, though the file object internal file point is NULL'd before releasing the GIL so I don't know if that seems plausible.

I'm not sure of the best way to trace back across the C/Python interpreter boundary - the trace above this is really just a lot of PyEval_EvalFrameEx/fast_function/call_function entry points with Python objects that are fairly opaque to the VS debugger.

One thing I do find interesting is that sometimes after continuing past the failure point the tests actually run to completion.  Not sure if that means the issue might be more in test wrapper code than the tests themselves, or just that continuing past the flush failure in the debugger is something the test can't detect.

I'll try to break down the test module later tonight when I have some more time.

----------

_______________________________________
Python tracker <report at bugs.python.org>
<http://bugs.python.org/issue10207>
_______________________________________