I was running Django in development mode (python manage.py runserver 0.0.0.0:8002). I saved a python source file; Django automatically detected the change and reloaded the module (that's the usual behavior). Then a backtrace from glibc appeared in the middle of the log. Django web server kept running, so I assume that the bug hit a separate thread. I also assume that this is a Python bug due to the nature of the trace (came from glibc). That's all information that I have.

---- python version ----
Python 2.6.4 (r264:75706, Dec  7 2009, 18:45:15) 
[GCC 4.4.1] on linux2
Type "help", "copyright", "credits" or "license" for more information.

---- trace ----
Django version 1.1.1, using settings 'camg.settings'
Development server is running at http://0.0.0.0:8002/
Quit the server with CONTROL-C.
[18/Mar/2010 22:50:23] "GET / HTTP/1.1" 200 27012
[18/Mar/2010 22:50:23] "GET /static/css/camg.css HTTP/1.1" 304 0
[18/Mar/2010 22:50:23] "GET /static/images/consorciomg.png HTTP/1.1" 304 0
[18/Mar/2010 22:52:01] "GET /andar/SEC1-3/ HTTP/1.1" 200 6441
[18/Mar/2010 22:52:06] "GET /switch/SEC1-3-3A-SA01/ HTTP/1.1" 200 6546
[18/Mar/2010 22:52:11] "GET /sala/3/ HTTP/1.1" 500 69619
[18/Mar/2010 22:52:13] "GET /switch/SEC1-3-3A-SA01/ HTTP/1.1" 200 6546
*** glibc detected *** /usr/bin/python: double free or corruption (out): 0xb7651b80 ***
======= Backtrace: =========
/lib/tls/i686/cmov/libc.so.6[0x17aff1]
/lib/tls/i686/cmov/libc.so.6[0x17c6f2]
/lib/tls/i686/cmov/libc.so.6(cfree+0x6d)[0x17f7cd]
/usr/bin/python[0x80b9ceb]
/usr/bin/python[0x808e622]
/usr/bin/python[0x808e634]
/usr/bin/python[0x806a42b]
/usr/bin/python[0x808e634]
/usr/bin/python[0x808cf19]
/usr/bin/python(PyDict_SetItem+0x87)[0x808f377]
/usr/bin/python(_PyModule_Clear+0x99)[0x8090c49]
/usr/bin/python(PyImport_Cleanup+0x459)[0x80edaf9]
/usr/bin/python(Py_Finalize+0xa5)[0x80fa305]
/usr/bin/python[0x80f9daf]
/usr/bin/python(PyErr_PrintEx+0x18d)[0x80f9f9d]
/usr/bin/python(PyErr_Print+0x12)[0x80fa1d2]
/usr/bin/python(PyRun_SimpleFileExFlags+0x1ab)[0x80facfb]
/usr/bin/python(Py_Main+0xaa8)[0x805c8d8]
/usr/bin/python(main+0x1b)[0x805baeb]
/lib/tls/i686/cmov/libc.so.6(__libc_start_main+0xe6)[0x126b56]
/usr/bin/python[0x805ba31]
======= Memory map: ========
00110000-0024e000 r-xp 00000000 08:01 553        /lib/tls/i686/cmov/libc-2.10.1.so
0024e000-0024f000 ---p 0013e000 08:01 553        /lib/tls/i686/cmov/libc-2.10.1.so
0024f000-00251000 r--p 0013e000 08:01 553        /lib/tls/i686/cmov/libc-2.10.1.so
00251000-00252000 rw-p 00140000 08:01 553        /lib/tls/i686/cmov/libc-2.10.1.so
00252000-00255000 rw-p 00000000 00:00 0 
00255000-00382000 r-xp 00000000 08:01 3085       /lib/i686/cmov/libcrypto.so.0.9.8
00382000-0038a000 r--p 0012c000 08:01 3085       /lib/i686/cmov/libcrypto.so.0.9.8
0038a000-00397000 rw-p 00134000 08:01 3085       /lib/i686/cmov/libcrypto.so.0.9.8
00397000-0039b000 rw-p 00000000 00:00 0 
0039b000-003bc000 r-xp 00000000 08:01 1749       /usr/lib/libpq.so.5.2
003bc000-003bd000 r--p 00020000 08:01 1749       /usr/lib/libpq.so.5.2
003bd000-003be000 rw-p 00021000 08:01 1749       /usr/lib/libpq.so.5.2
003be000-003c0000 r-xp 00000000 08:01 560        /lib/libcom_err.so.2.1
003c0000-003c1000 r--p 00001000 08:01 560        /lib/libcom_err.so.2.1
003c1000-003c2000 rw-p 00002000 08:01 560        /lib/libcom_err.so.2.1
003c2000-003e8000 r-xp 00000000 08:01 1307       /usr/lib/libk5crypto.so.3.1
003e8000-003e9000 ---p 00026000 08:01 1307       /usr/lib/libk5crypto.so.3.1
003e9000-003ea000 r--p 00026000 08:01 1307       /usr/lib/libk5crypto.so.3.1
003ea000-003eb000 rw-p 00027000 08:01 1307       /usr/lib/libk5crypto.so.3.1
003eb000-003f1000 r-xp 00000000 08:01 914        /usr/lib/libkrb5support.so.0.1
003f1000-003f2000 r--p 00005000 08:01 914        /usr/lib/libkrb5support.so.0.1
003f2000-003f3000 rw-p 00006000 08:01 914        /usr/lib/libkrb5support.so.0.1
003f3000-00400000 r-xp 00000000 08:01 4464       /usr/lib/liblber-2.4.so.2.5.1
00400000-00401000 r--p 0000c000 08:01 4464       /usr/lib/liblber-2.4.so.2.5.1
00401000-00402000 rw-p 0000d000 08:01 4464       /usr/lib/liblber-2.4.so.2.5.1
00402000-0041a000 r-xp 00000000 08:01 4704       /usr/lib/libsasl2.so.2.0.23
0041a000-0041b000 r--p 00017000 08:01 4704       /usr/lib/libsasl2.so.2.0.23
0041b000-0041c000 rw-p 00018000 08:01 4704       /usr/lib/libsasl2.so.2.0.23
0041c000-004bf000 r-xp 00000000 08:01 4258       /usr/lib/libgnutls.so.26.14.10
004bf000-004c3000 r--p 000a2000 08:01 4258       /usr/lib/libgnutls.so.26.14.10
004c3000-004c4000 rw-p 000a6000 08:01 4258       /usr/lib/libgnutls.so.26.14.10
004c4000-004d0000 r-xp 00000000 08:01 328860     /usr/lib/python2.6/dist-packages/mx/DateTime/mxDateTime/mxDateTime.so
004d0000-004d1000 r--p 0000b000 08:01 328860     /usr/lib/python2.6/dist-packages/mx/DateTime/mxDateTime/mxDateTime.so
004d1000-004d2000 rw-p 0000c000 08:01 328860     /usr/lib/python2.6/dist-packages/mx/DateTime/mxDateTime/mxDateTime.so
004d2000-004e5000 r-xp 00000000 08:01 606        /lib/tls/i686/cmov/libnsl-2.10.1.so
004e5000-004e6000 r--p 00012000 08:01 606        /lib/tls/i686/cmov/libnsl-2.10.1.so
004e6000-004e7000 rw-p 00013000 08:01 606        /lib/tls/i686/cmov/libnsl-2.10.1.so
004e7000-004e9000 rw-p 00000000 00:00 0 
004e9000-004f2000 r-xp 00000000 08:01 632        /lib/tls/i686/cmov/libnss_nis-2.10.1.so
004f2000-004f3000 r--p 00008000 08:01 632        /lib/tls/i686/cmov/libnss_nis-2.10.1.so
004f3000-004f4000 rw-p 00009000 08:01 632        /lib/tls/i686/cmov/libnss_nis-2.10.1.so
004f9000-0053a000 r-xp 00000000 08:01 3086       /lib/i686/cmov/libssl.so.0.9.8
0053a000-0053b000 ---p 00041000 08:01 3086       /lib/i686/cmov/libssl.so.0.9.8
0053b000-0053c000 r--p 00041000 08:01 3086       /lib/i686/cmov/libssl.so.0.9.8
0053c000-0053f000 rw-p 00042000 08:01 3086       /lib/i686/cmov/libssl.so.0.9.8
0053f000-005b8000 r-xp 00000000 08:01 581        /lib/libgcrypt.so.11.5.2
005b8000-005b9000 r--p 00078000 08:01 581        /lib/libgcrypt.so.11.5.2
005b9000-005bb000 rw-p 00079000 08:01 581        /lib/libgcrypt.so.11.5.2
005bb000-005d7000 r-xp 00000000 08:01 3077       /lib/libgcc_s.so.1
005d7000-005d8000 r--p 0001b000 08:01 3077       /lib/libgcc_s.so.1
005d8000-005d9000 rw-p 0001c000 08:01 3077       /lib/libgcc_s.so.1
005e9000-005ea000 r-xp 00000000 00:00 0          [vdso]
00639000-00642000 r-xp 00000000 08:01 595        /lib/tls/i686/cmov/libcrypt-2.10.1.so
00642000-00643000 r--p 00008000 08:01 595        /lib/tls/i686/cmov/libcrypt-2.10.1.so
00643000-00644000 rw-p 00009000 08:01 595        /lib/tls/i686/cmov/libcrypt-2.10.1.so
00644000-0066b000 rw-p 00000000 00:00 0 
0068e000-00690000 r-xp 00000000 08:01 10509      /lib/tls/i686/cmov/libutil-2.10.1.so
00690000-00691000 r--p 00001000 08:01 10509      /lib/tls/i686/cmov/libutil-2.10.1.so
00691000-00692000 rw-p 00002000 08:01 10509      /lib/tls/i686/cmov/libutil-2.10.1.so
00697000-00699000 r-xp 00000000 08:01 266595     /usr/lib/python2.6/lib-dynload/_hashlib.so
00699000-0069a000 r--p 00001000 08:01 266595     /usr/lib/python2.6/lib-dynload/_hashlib.so
0069a000-0069b000 rw-p 00002000 08:01 266595     /usr/lib/python2.6/lib-dynload/_hashlib.so
00774000-00788000 r-xp 00000000 08:01 681        /lib/libz.so.1.2.3.3
00788000-00789000 r--p 00013000 08:01 681        /lib/libz.so.1.2.3.3
00789000-0078a000 rw-p 00014000 08:01 681        /lib/libz.so.1.2.3.3
00841000-00851000 r-xp 00000000 08:01 658        /lib/tls/i686/cmov/libresolv-2.10.1.so
00851000-00852000 r--p 00010000 08:01 658        /lib/tls/i686/cmov/libresolv-2.10.1.so
00852000-00853000 rw-p 00011000 08:01 658        /lib/tls/i686/cmov/libresolv-2.10.1.so
00853000-00855000 rw-p 00000000 00:00 0 
0089f000-008a1000 r-xp 00000000 08:01 597        /lib/tls/i686/cmov/libdl-2.10.1.so
008a1000-008a2000 r--p 00001000 08:01 597        /lib/tls/i686/cmov/libdl-2.10.1.so
008a2000-008a3000 rw-p 00002000 08:01 597        /lib/tls/i686/cmov/libdl-2.10.1.so
008ea000-00905000 r-xp 00000000 08:01 67         /lib/ld-2.10.1.so
00905000-00906000 r--p 0001a000 08:01 67         /lib/ld-2.10.1.so
00906000-00907000 rw-p 0001b000 08:01 67         /lib/ld-2.10.1.so
00940000-00950000 r-xp 00000000 08:01 4761       /usr/lib/libtasn1.so.3.1.5

Python was displaying an error: did you saw the error? I don't know where Django logs stderr.

Could you also run Python in verbose mode? Set PYTHONVERBOSE=2 environment variable. It should write useful informations before the crash.

I know I have little information but unfortunately I couldn't reproduce the
crash. Seems like a racing condition or something similar. I'll see what I
can do about it.

On Fri, Mar 19, 2010 at 07:46, STINNER Victor <report@bugs.python.org>wrote:

>
> STINNER Victor <victor.stinner@haypocalc.com> added the comment:
>
> Python was displaying an error: did you saw the error? I don't know where
> Django logs stderr.
>
> Could you also run Python in verbose mode? Set PYTHONVERBOSE=2 environment
> variable. It should write useful informations before the crash.
>
> ----------
> nosy: +haypo
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue8176>
> _______________________________________
>

Clearly not enough information, but I have a few observations:

1. Clearly the crash occurs on exit (in Py_Finalize) during a module cleanup.  (Unfortunately it looks like a non-debug build of Python was used so figuring out which module is involved may be hard. 

2. Memory map suggests that the crash is very late in python finalization.  Note that only two python modules are still mapped: mxDateTime and _hashlib.  However the memmap seems incomplete.

Try to reproduce the crash with a debug build of python (configure --with-pydebug).  The debug build may also crash sooner and more reliably.

Thanks for investigating!

I'll keep watching. I'm currently developing a small Django app, and the
crash happened during one of the automatic reloads that the development
server do whenever a source code file changes. The problem is that I
probably ran through the same procedure several hundred times over the past
few weeks, but the bug happened only *once*. Seems like a nasty bug. I
*suspect* it may be thread related, a racing condition or something like it.
(and yes, I'm using a regular build, not a debug build).

Also note that I use Python since 1998 and never, in the past 12 years, I
had a dump like this.

As for this ticket, it seems like a nasty and elusive bug; I _feel_ that we
may never see the same bug again, _but_ other people may encounter similar
situations, and we can then try to correlate them to find the cause. If I
don't manage to reproduce it over the next few days we may close it but keep
it in the tracker, until someone else hits it again.

Best regards,

Carlos Ribeiro

On Sun, Mar 21, 2010 at 16:29, Alexander Belopolsky
<report@bugs.python.org>wrote:

>
> Alexander Belopolsky <alexander.belopolsky@gmail.com> added the comment:
>
> Clearly not enough information, but I have a few observations:
>
> 1. Clearly the crash occurs on exit (in Py_Finalize) during a module
> cleanup.  (Unfortunately it looks like a non-debug build of Python was used
> so figuring out which module is involved may be hard.
>
> 2. Memory map suggests that the crash is very late in python finalization.
>  Note that only two python modules are still mapped: mxDateTime and
> _hashlib.  However the memmap seems incomplete.
>
> Try to reproduce the crash with a debug build of python (configure
> --with-pydebug).  The debug build may also crash sooner and more reliably.
>
> ----------
> nosy: +Alexander.Belopolsky
>
> _______________________________________
> Python tracker <report@bugs.python.org>
> <http://bugs.python.org/issue8176>
> _______________________________________
>

It looks like the bug cannot be reproduced anymore.  Since it was discovered using a python instance with third-party extension modules, it may not even be a python bug to begin with.

If you are still able to reproduce the bug, you may try the following module to get a backtrace: https://github.com/haypo/faulthandler/

Victor,

I was thinking about pointing the OP to your faulthandler module, but decided not to because in the failing thread python has already finished execution and most of finalization.  It is very unlikely that faulthandler will be helpful in this scenario.

I wouldn't be surprised if the crash was related to some concurrency issues during shutdown. Other (Python or not Python) threads can continue running while the main thread is running Py_Finalize; this might be the reason; or perhaps some extension modules don't really support reloading.

I'm closing the bug because it hasn't seen any activity in the past 2.5 years.