Old Python binary eats all mem after upgrade to 2.28

Old Python binary eats all mem after upgrade to 2.28

[Michael Brunnbauer]

[-- Attachment #1: Type: text/plain, Size: 1398 bytes --]


hi all,

I just upgraded to glibc 2.28 and everything seems to run fine - except this
old binary of Python 2.1.3 from 2002 that came precompiled with Zope 2.6.0.
When I start it on the command line, it starts eating up all memory until
it gets killed by the oom-killer. strace looks like this:

mremap(0xe64aa000, 225259520, 225263616, MREMAP_MAYMOVE) = 0xe64aa000
mremap(0xe64aa000, 225263616, 225267712, MREMAP_MAYMOVE) = 0xe64aa000
mremap(0xe64aa000, 225267712, 225271808, MREMAP_MAYMOVE) = 0xe64aa000
mremap(0xe64aa000, 225271808, 225275904, MREMAP_MAYMOVE) = 0xe64aa000
mremap(0xe64aa000, 225275904, 225280000, MREMAP_MAYMOVE) = 0xe64aa000
mremap(0xe64aa000, 225280000, 225284096, MREMAP_MAYMOVE) = 0xe64aa000
...

I am in the very difficult process of moving away from that particular legacy 
but this will take time. Also I'm concerned about other old binaries that may 
stop working.

Any idea what is going on?

Regards,

Michael Brunnbauer

-- 
++  Michael Brunnbauer
++  netEstate GmbH
++  Geisenhausener Straße 11a
++  81379 München
++  Tel +49 89 32 19 77 80
++  Fax +49 89 32 19 77 89 
++  E-Mail brunni@netestate.de
++  https://www.netestate.de/
++
++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
++  USt-IdNr. DE221033342
++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]

Re: Old Python binary eats all mem after upgrade to 2.28

[Michael Brunnbauer]

[-- Attachment #1: Type: text/plain, Size: 2660 bytes --]


hi all,

I should have provided more strace-context. This is what happens shortly 
before the endless mremap starts:

stat64("/home/zope/2.6.0/lib/python2.1/site-packages", {st_mode=S_IFDIR|0775, st_size=304, ...}) = 0
openat(AT_FDCWD, "/home/zope/2.6.0/lib/python2.1/site-packages", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 4
fstat64(4, {st_mode=S_IFDIR|0775, st_size=304, ...}) = 0
brk(0x812c000)                          = 0x812c000
getdents(4, /* 10 entries */, 32768)    = 244
mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf73e2000
mremap(0xf73e2000, 135168, 139264, MREMAP_MAYMOVE) = 0xf73c0000
...

cu,
brunni

On Wed, Aug 08, 2018 at 03:54:39PM +0200, Michael Brunnbauer wrote:
> 
> hi all,
> 
> I just upgraded to glibc 2.28 and everything seems to run fine - except this
> old binary of Python 2.1.3 from 2002 that came precompiled with Zope 2.6.0.
> When I start it on the command line, it starts eating up all memory until
> it gets killed by the oom-killer. strace looks like this:
> 
> mremap(0xe64aa000, 225259520, 225263616, MREMAP_MAYMOVE) = 0xe64aa000
> mremap(0xe64aa000, 225263616, 225267712, MREMAP_MAYMOVE) = 0xe64aa000
> mremap(0xe64aa000, 225267712, 225271808, MREMAP_MAYMOVE) = 0xe64aa000
> mremap(0xe64aa000, 225271808, 225275904, MREMAP_MAYMOVE) = 0xe64aa000
> mremap(0xe64aa000, 225275904, 225280000, MREMAP_MAYMOVE) = 0xe64aa000
> mremap(0xe64aa000, 225280000, 225284096, MREMAP_MAYMOVE) = 0xe64aa000
> ...
> 
> I am in the very difficult process of moving away from that particular legacy 
> but this will take time. Also I'm concerned about other old binaries that may 
> stop working.
> 
> Any idea what is going on?
> 
> Regards,
> 
> Michael Brunnbauer
> 
> -- 
> ++  Michael Brunnbauer
> ++  netEstate GmbH
> ++  Geisenhausener Straße 11a
> ++  81379 München
> ++  Tel +49 89 32 19 77 80
> ++  Fax +49 89 32 19 77 89 
> ++  E-Mail brunni@netestate.de
> ++  https://www.netestate.de/
> ++
> ++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
> ++  USt-IdNr. DE221033342
> ++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
> ++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel



-- 
++  Michael Brunnbauer
++  netEstate GmbH
++  Geisenhausener Straße 11a
++  81379 München
++  Tel +49 89 32 19 77 80
++  Fax +49 89 32 19 77 89 
++  E-Mail brunni@netestate.de
++  https://www.netestate.de/
++
++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
++  USt-IdNr. DE221033342
++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]

Re: Old Python binary eats all mem after upgrade to 2.28

[Florian Weimer]

On 08/08/2018 04:03 PM, Michael Brunnbauer wrote:
> I should have provided more strace-context. This is what happens shortly
> before the endless mremap starts:
> 
> stat64("/home/zope/2.6.0/lib/python2.1/site-packages", {st_mode=S_IFDIR|0775, st_size=304, ...}) = 0
> openat(AT_FDCWD, "/home/zope/2.6.0/lib/python2.1/site-packages", O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_CLOEXEC) = 4
> fstat64(4, {st_mode=S_IFDIR|0775, st_size=304, ...}) = 0
> brk(0x812c000)                          = 0x812c000
> getdents(4, /* 10 entries */, 32768)    = 244
> mmap2(NULL, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf73e2000
> mremap(0xf73e2000, 135168, 139264, MREMAP_MAYMOVE) = 0xf73c0000
> ...

Could you attach gdb and see which glibc function, if any, is called 
here?  Is there code from a Python extension module on the call stack?

Thanks,
Florian

Re: Old Python binary eats all mem after upgrade to 2.28

[Michael Brunnbauer]

[-- Attachment #1: Type: text/plain, Size: 5269 bytes --]


Hello Florian,

On Wed, Aug 08, 2018 at 04:54:04PM +0200, Florian Weimer wrote:
> Could you attach gdb and see which glibc function, if any, is called here?
> Is there code from a Python extension module on the call stack?

I'm not used to gdb and hope I did everything right:

Reading symbols from ./bin/python...done.
(gdb) catch syscall mremap
Catchpoint 1 (syscall 'mremap' [163])
(gdb) run
Starting program: /home/zope/old/2.6.0/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".

Catchpoint 1 (call to syscall mremap), 0xf7fd5c12 in _dl_sysinfo_int80 ()
   from /lib/ld-linux.so.2
(gdb) continue 1000
Will ignore next 999 crossings of breakpoint 1.  Continuing.

Catchpoint 1 (call to syscall mremap), 0xf7fd5c12 in _dl_sysinfo_int80 ()
   from /lib/ld-linux.so.2
(gdb) continue 10000
Will ignore next 9999 crossings of breakpoint 1.  Continuing.

Catchpoint 1 (call to syscall mremap), 0xf7fd5c12 in _dl_sysinfo_int80 ()
   from /lib/ld-linux.so.2
(gdb) bt
#0  0xf7fd5c12 in _dl_sysinfo_int80 () from /lib/ld-linux.so.2
#1  0xf7ddda63 in mremap () at ../sysdeps/unix/syscall-template.S:78
#2  0xf7d54710 in mremap_chunk (p=p@entry=0xf5ad8008, new_size=22667264,
    new_size@entry=22663216) at malloc.c:2861
#3  0xf7d5906b in __GI___libc_realloc (oldmem=0xf5ad8010, bytes=22663201)
    at malloc.c:3185
#4  0x08081214 in ins1 (self=0x80c7dfc, where=5665700, v=0x80ca680)
    at Objects/listobject.c:134
#5  0x080812e3 in PyList_Append (op=0x80c7dfc, newitem=0x80ca680)
    at Objects/listobject.c:169
#6  0x0806fb2f in posix_listdir (self=0x0, args=0x80d542c)
    at ./Modules/posixmodule.c:1028
#7  0x08058b12 in call_cfunction (func=0x80e5e20, arg=0x80d542c, kw=0x0)
    at Python/ceval.c:2867
#8  0x08057580 in eval_code2 (co=0x80d3460, globals=0x80d2ccc, locals=0x0,
    args=0x80d0e5c, argcount=1, kws=0x80d0e60, kwcount=0, defs=0x0,
    defcount=0, closure=0x0) at Python/ceval.c:1960
#9  0x08058e57 in fast_function (func=0x80d5e0c, pp_stack=0xffffc758, n=1,
    na=1, nk=0) at Python/ceval.c:3035
#10 0x08057689 in eval_code2 (co=0x80d5fd0, globals=0x80d2ccc,
    locals=0x80d2ccc, args=0x0, argcount=0, kws=0x0, kwcount=0, defs=0x0,
    defcount=0, closure=0x0) at Python/ceval.c:1984
#11 0x080549b7 in PyEval_EvalCode (co=0x80d5fd0, globals=0x80d2ccc,
---Type <return> to continue, or q <return> to quit---
    locals=0x80d2ccc) at Python/ceval.c:341
#12 0x080646d7 in PyImport_ExecCodeModuleEx (name=0xffffd084 "site",
    co=0x80d5fd0,
    pathname=0xffffc7dc "/home/zope/old/2.6.0/lib/python2.1/site.pyc")
    at Python/import.c:490
#13 0x08064b41 in load_source_module (name=0xffffd084 "site",
    pathname=0xffffcc24 "/home/zope/old/2.6.0/lib/python2.1/site.py",
    fp=0x80c7530) at Python/import.c:754
#14 0x0806528b in load_module (name=0xffffd084 "site", fp=0x80c7530,
    buf=0xffffcc24 "/home/zope/old/2.6.0/lib/python2.1/site.py", type=1)
    at Python/import.c:1301
#15 0x08065d25 in import_submodule (mod=0x80b3f8c <_Py_NoneStruct>,
    subname=0xffffd084 "site", fullname=0xffffd084 "site")
    at Python/import.c:1829
#16 0x08065977 in load_next (mod=0x80b3f8c <_Py_NoneStruct>,
    altmod=0x80b3f8c <_Py_NoneStruct>, p_name=0xffffd490,
    buf=0xffffd084 "site", p_buflen=0xffffd080) at Python/import.c:1685
#17 0x08065660 in import_module_ex (name=0x0, globals=0x80ced1c,
    locals=0x80ced1c, fromlist=0x80c81ac) at Python/import.c:1536
#18 0x08065774 in PyImport_ImportModuleEx (name=0x80cee64 "site",
    globals=0x80ced1c, locals=0x80ced1c, fromlist=0x80c81ac)
    at Python/import.c:1577
#19 0x08094ab0 in builtin___import__ (self=0x0, args=0x80c829c)
---Type <return> to continue, or q <return> to quit---
    at Python/bltinmodule.c:31
#20 0x08058b12 in call_cfunction (func=0x80c3400, arg=0x80c829c, kw=0x0)
    at Python/ceval.c:2867
#21 0x08058a10 in call_object (func=0x80c3400, arg=0x80c829c, kw=0x0)
    at Python/ceval.c:2820
#22 0x080588fe in PyEval_CallObjectWithKeywords (func=0x80c3400,
    arg=0x80c829c, kw=0x0) at Python/ceval.c:2753
#23 0x0807800b in PyObject_CallObject (o=0x80c3400, a=0x80c829c)
    at Objects/abstract.c:1529
#24 0x0807809e in PyObject_CallFunction (callable=0x80c3400,
    format=0x809db87 "OOOO") at Objects/abstract.c:1570
#25 0x08066011 in PyImport_Import (module_name=0x80cee50)
    at Python/import.c:1967
#26 0x080655e1 in PyImport_ImportModule (name=0x809ed63 "site")
    at Python/import.c:1508
#27 0x080696f9 in initsite () at Python/pythonrun.c:428
#28 0x0806940c in Py_Initialize () at Python/pythonrun.c:156
#29 0x08051c63 in Py_Main (argc=1, argv=0xffffd6b4) at Modules/main.c:275
#30 0x080518d6 in main (argc=1, argv=0xffffd6b4) at Modules/python.c:10
(gdb)

Regards,

Michael Brunnbauer

-- 
++  Michael Brunnbauer
++  netEstate GmbH
++  Geisenhausener Straße 11a
++  81379 München
++  Tel +49 89 32 19 77 80
++  Fax +49 89 32 19 77 89 
++  E-Mail brunni@netestate.de
++  https://www.netestate.de/
++
++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
++  USt-IdNr. DE221033342
++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]

Re: Old Python binary eats all mem after upgrade to 2.28

[Florian Weimer]

On 08/08/2018 10:23 PM, Michael Brunnbauer wrote:
> #6  0x0806fb2f in posix_listdir (self=0x0, args=0x80d542c)
>      at ./Modules/posixmodule.c:1028

I would expect that posix_listdir is looping for some reason.  Perhaps 
you can single-step through it and confirm this hypothesis?

Do you have a copy the source code (posixmodule.c)?

Thanks,
Florian

Re: Old Python binary eats all mem after upgrade to 2.28

[Michael Brunnbauer]

[-- Attachment #1: Type: text/plain, Size: 3892 bytes --]


Hello Florian,

On Thu, Aug 09, 2018 at 08:27:46AM +0200, Florian Weimer wrote:
> On 08/08/2018 10:23 PM, Michael Brunnbauer wrote:
> > #6  0x0806fb2f in posix_listdir (self=0x0, args=0x80d542c)
> >      at ./Modules/posixmodule.c:1028
> 
> I would expect that posix_listdir is looping for some reason.  Perhaps you
> can single-step through it and confirm this hypothesis?
> 
> Do you have a copy the source code (posixmodule.c)?

https://www.python.org/ftp/python/2.1.3/Python-2.1.3.tgz

The loop seems to be this one (starting with line 1017 of posixmodule.c,
which was my breakpoint when testing it):

        while ((ep = readdir(dirp)) != NULL) {
                if (ep->d_name[0] == '.' &&
                    (NAMLEN(ep) == 1 ||
                     (ep->d_name[1] == '.' && NAMLEN(ep) == 2)))
                        continue;
                v = PyString_FromStringAndSize(ep->d_name, NAMLEN(ep));
                if (v == NULL) {
                        Py_DECREF(d);
                        d = NULL;
                        break;
                }
                if (PyList_Append(d, v) != 0) {
                        Py_DECREF(v);
                        Py_DECREF(d);
                        d = NULL;
                        break;
                }
                Py_DECREF(v);
        }

Here is a sample gdb session. It seems readdir always returns the same empty
string:

Reading symbols from ./bin/python...done.
(gdb) b posixmodule.c:1017
Breakpoint 1 at 0x806fad7: file ./Modules/posixmodule.c, line 1017.
(gdb) run
Starting program: /home/zope/old/2.6.0/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/libthread_db.so.1".

Breakpoint 1, posix_listdir (self=0x0, args=0x80d542c)
    at ./Modules/posixmodule.c:1018
1018    ./Modules/posixmodule.c: No such file or directory.
(gdb) continue 10000
Will ignore next 9999 crossings of breakpoint 1.  Continuing.

Breakpoint 1, posix_listdir (self=0x0, args=0x80d542c)
    at ./Modules/posixmodule.c:1018
1018    in ./Modules/posixmodule.c
(gdb) print ep
$1 = (struct dirent *) 0x8103c0c
(gdb) print ep->d_name
$2 = "\000\207V\000\000\200\016\315\022\020\000\000..\000\000\000\034Z\000\000\200\264\265\026$\000\000_mysql_exceptions.pyc\000\000\000\000\035Z\000\000\200\362\034!\024\000\000README\000\000\000\036Z\000\000\200w\323\070 \000\000CompatMysqldb.pyc\000\000\000\000\037Z\000\000\200\240Y;\030\000\000_mysql.so\000\000\000\000 Z\000\000\200\370vT\024\000\000csv.so\000\000\000!Z\000\000\200\314\314^\034\000\000CompatMysqldb.py\000\"Z\000\000\000\276\332v \000\000_mysql_excep"...
(gdb) continue 10
Will ignore next 9 crossings of breakpoint 1.  Continuing.

Breakpoint 1, posix_listdir (self=0x0, args=0x80d542c)
    at ./Modules/posixmodule.c:1018
1018    in ./Modules/posixmodule.c
(gdb) print ep
$3 = (struct dirent *) 0x8103c0c
(gdb) print ep->d_name
$4 = "\000\207V\000\000\200\016\315\022\020\000\000..\000\000\000\034Z\000\000\200\264\265\026$\000\000_mysql_exceptions.pyc\000\000\000\000\035Z\000\000\200\362\034!\024\000\000README\000\000\000\036Z\000\000\200w\323\070 \000\000CompatMysqldb.pyc\000\000\000\000\037Z\000\000\200\240Y;\030\000\000_mysql.so\000\000\000\000 Z\000\000\200\370vT\024\000\000csv.so\000\000\000!Z\000\000\200\314\314^\034\000\000CompatMysqldb.py\000\"Z\000\000\000\276\332v \000\000_mysql_excep"...

Regards,

Michael Brunnbauer

-- 
++  Michael Brunnbauer
++  netEstate GmbH
++  Geisenhausener Straße 11a
++  81379 München
++  Tel +49 89 32 19 77 80
++  Fax +49 89 32 19 77 89 
++  E-Mail brunni@netestate.de
++  https://www.netestate.de/
++
++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
++  USt-IdNr. DE221033342
++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]

Re: Old Python binary eats all mem after upgrade to 2.28

[Florian Weimer]

On 08/09/2018 09:32 AM, Michael Brunnbauer wrote:

> Breakpoint 1, posix_listdir (self=0x0, args=0x80d542c)
>      at ./Modules/posixmodule.c:1018
> 1018    in ./Modules/posixmodule.c
> (gdb) print ep
> $1 = (struct dirent *) 0x8103c0c
> (gdb) print ep->d_name
> $2 = "\000\207V\000\000\200\016\315\022\020\000\000..\000\000\000\034Z\000\000\200\264\265\026$\000\000_mysql_exceptions.pyc\000\000\000\000\035Z\000\000\200\362\034!\024\000\000README\000\000\000\036Z\000\000\200w\323\070 \000\000CompatMysqldb.pyc\000\000\000\000\037Z\000\000\200\240Y;\030\000\000_mysql.so\000\000\000\000 Z\000\000\200\370vT\024\000\000csv.so\000\000\000!Z\000\000\200\314\314^\034\000\000CompatMysqldb.py\000\"Z\000\000\000\276\332v \000\000_mysql_excep"...
> (gdb) continue 10
> Will ignore next 9 crossings of breakpoint 1.  Continuing.
> 
> Breakpoint 1, posix_listdir (self=0x0, args=0x80d542c)
>      at ./Modules/posixmodule.c:1018
> 1018    in ./Modules/posixmodule.c
> (gdb) print ep
> $3 = (struct dirent *) 0x8103c0c
> (gdb) print ep->d_name
> $4 = "\000\207V\000\000\200\016\315\022\020\000\000..\000\000\000\034Z\000\000\200\264\265\026$\000\000_mysql_exceptions.pyc\000\000\000\000\035Z\000\000\200\362\034!\024\000\000README\000\000\000\036Z\000\000\200w\323\070 \000\000CompatMysqldb.pyc\000\000\000\000\037Z\000\000\200\240Y;\030\000\000_mysql.so\000\000\000\000 Z\000\000\200\370vT\024\000\000csv.so\000\000\000!Z\000\000\200\314\314^\034\000\000CompatMysqldb.py\000\"Z\000\000\000\276\332v \000\000_mysql_excep"...

This looks like the parser for the getdtents output getting 
desynchronized.  I don't remember anyone reporting anything like this 
before.

I have an idea what might be going on.  I'll try to write a test case to 
reproduce this.


Thanks,
Florian

Re: Old Python binary eats all mem after upgrade to 2.28

[Florian Weimer]

On 08/09/2018 10:39 AM, Florian Weimer wrote:

> This looks like the parser for the getdtents output getting 
> desynchronized.  I don't remember anyone reporting anything like this 
> before.
> 
> I have an idea what might be going on.  I'll try to write a test case to 
> reproduce this.

Bug filed: https://sourceware.org/bugzilla/show_bug.cgi?id=23497

Thanks,
Florian

Re: Old Python binary eats all mem after upgrade to 2.28

[Michael Brunnbauer]

[-- Attachment #1: Type: text/plain, Size: 741 bytes --]


Hello Florian,

On Thu, Aug 09, 2018 at 11:21:10AM +0200, Florian Weimer wrote:
> Bug filed: https://sourceware.org/bugzilla/show_bug.cgi?id=23497

Thanks! This looks like it might affect more old binaries so I'll probably wait
for a patch before rolling out 2.28 completely.

Regards,

Michael Brunnbauer

-- 
++  Michael Brunnbauer
++  netEstate GmbH
++  Geisenhausener Straße 11a
++  81379 München
++  Tel +49 89 32 19 77 80
++  Fax +49 89 32 19 77 89 
++  E-Mail brunni@netestate.de
++  https://www.netestate.de/
++
++  Sitz: München, HRB Nr.142452 (Handelsregister B München)
++  USt-IdNr. DE221033342
++  Geschäftsführer: Michael Brunnbauer, Franz Brunnbauer
++  Prokurist: Dipl. Kfm. (Univ.) Markus Hendel

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 163 bytes --]