classification
Title: Illegal instruction at Python-2.7.5/Modules/_sre.c:1173
Type: crash Stage: resolved
Components: Interpreter Core Versions: Python 2.7
process
Status: closed Resolution: not a bug
Dependencies: Superseder:
Assigned To: Nosy List: mmokrejs, pitrou, tim.peters, vstinner
Priority: normal Keywords:

Created on 2013-08-31 22:26 by mmokrejs, last changed 2013-12-01 20:22 by mmokrejs. This issue is now closed.

Files
File name Uploaded Description Edit
core.emerge.4097.gdb.txt mmokrejs, 2013-08-31 22:26
Messages (6)
msg196684 - (view) Author: Martin Mokrejs (mmokrejs) Date: 2013-08-31 22:26
I was trying to use DUMA to find errors in python runtime and it indeed killed python-based utility called emerge. Let's see what you say now:

# export LD_PRELOAD=/usr/lib64/libduma.so.0.0.0
# sysctl -w vm.max_map_count=1000000

# emerge dev-lang/python:2.7 
DUMA 2.5.15 (shared library, NO_LEAKDETECTION)
Copyright (C) 2006 Michael Eddington <meddington@gmail.com>
Copyright (C) 2002-2008 Hayati Ayguen <h_ayguen@web.de>, Procitec GmbH
Copyright (C) 1987-1999 Bruce Perens <bruce@perens.com>

DUMA 2.5.15 (shared library, NO_LEAKDETECTION)
Copyright (C) 2006 Michael Eddington <meddington@gmail.com>
Copyright (C) 2002-2008 Hayati Ayguen <h_ayguen@web.de>, Procitec GmbH
Copyright (C) 1987-1999 Bruce Perens <bruce@perens.com>

DUMA 2.5.15 (shared library, NO_LEAKDETECTION)
Copyright (C) 2006 Michael Eddington <meddington@gmail.com>
Copyright (C) 2002-2008 Hayati Ayguen <h_ayguen@web.de>, Procitec GmbH
Copyright (C) 1987-1999 Bruce Perens <bruce@perens.com>


DUMA Aborting: mprotect() failed: Cannot allocate memory.
Check README section 'MEMORY USAGE AND EXECUTION SPEED'
  if your (Linux) system may limit the number of different page mappings per process
Illegal instruction (core dumped)
# ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 127104
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 127104
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited
#

(gdb) where
#0  0x00007febd6ed84d7 in kill () from /lib64/libc.so.6
#1  0x00007febd78e2f9c in DUMA_Abort () from /usr/lib64/libduma.so.0.0.0
#2  0x00007febd78e1b77 in _duma_allocate () from /usr/lib64/libduma.so.0.0.0
#3  0x00007febd78e1fef in _duma_malloc () from /usr/lib64/libduma.so.0.0.0
#4  0x00007febd7626c60 in sre_umatch (state=0x7fff96f0de10, pattern=0x7feb2804ecb8) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Modules/_sre.c:1173
#5  0x00007febd762932f in pattern_match (self=0x7feb2804ec58, args=(u'>=gnome-base/libbonobo-2.32::gentoo-haskell',), kw=0x0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Modules/_sre.c:1896
#6  0x00007febd751ffcc in PyCFunction_Call (func=<built-in method match of _sre.SRE_Pattern object at remote 0x7feb2804ec58>, arg=(u'>=gnome-base/libbonobo-2.32::gentoo-haskell',), kw=0x0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Objects/methodobject.c:85
#7  0x00007febd75c4b81 in call_function (pp_stack=0x7fff96f0e6d0, oparg=1) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Python/ceval.c:4021
#8  0x00007febd75bf6c6 in PyEval_EvalFrameEx (f=Frame 0x7feb374ebce8, for file /usr/lib64/portage/pym/portage/dep/__init__.py, line 1227, in __init__ (self=<Atom(blocker=False, eapi=None) at remote 0x7fea931d5fb0>, s=u'>=gnome-base/libbonobo-2.32::gentoo-haskell', unevaluated_atom=None, allow_wildcard=True, allow_repo=True, _use=None, eapi=None, is_valid_flag=None, eapi_attrs=<_eapi_attrs at remote 0x7feb31931f48>, atom_re=<_sre.SRE_Pattern at remote 0x7feb2804ec58>, blocker_prefix=u'', blocker=False), throwflag=0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Python/ceval.c:2666

[cut]

(gdb) bt full
#0  0x00007febd6ed84d7 in kill () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007febd78e2f9c in DUMA_Abort () from /usr/lib64/libduma.so.0.0.0
No symbol table info available.
#2  0x00007febd78e1b77 in _duma_allocate () from /usr/lib64/libduma.so.0.0.0
No symbol table info available.
#3  0x00007febd78e1fef in _duma_malloc () from /usr/lib64/libduma.so.0.0.0
No symbol table info available.
#4  0x00007febd7626c60 in sre_umatch (state=0x7fff96f0de10, pattern=0x7feb2804ecb8) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Modules/_sre.c:1173
        end = 0x7fea931cfffc
        alloc_pos = 1648
        ctx_pos = 1648
        i = 128
        ret = 0
        jump = 2
        sigcount = 187
        ctx = 0x7fea931fbcf8
        nextctx = 0x7fea931fbcf8
        __PRETTY_FUNCTION__ = "sre_umatch"
#5  0x00007febd762932f in pattern_match (self=0x7feb2804ec58, args=(u'>=gnome-base/libbonobo-2.32::gentoo-haskell',), kw=0x0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Modules/_sre.c:1896
        state = {ptr = 0x7fea931cffbc, beginning = 0x7fea931cff50, start = 0x7fea931cff50, end = 0x7fea931cfffc, string = u'>=gnome-base/libbonobo-2.32::gentoo-haskell', pos = 0, endpos = 43, charsize = 4, lastindex = 2, lastmark = 43, mark = {0x7fea931cff50, 0x0, 0x7fea931cff50, 0x7fea931cffbc, 0x7fea931cff50, 0x7fea931cff58, 0x7fea931cff58, 0x7fea931cffbc, 0x7fea931cff58, 0x7fea931cffa8, 0x0 <repeats 24 times>, 0x7fea931cffac, 0x7fea931cffb0, 0x7fea931cffb0, 0x7fea931cffbc, 0x7fea931cffb0, 0x7fea931cffbc, 0x7fea931cffbc, 0x7fea931cffbc, 0x7fea931cffbc, 0x7fea931cffbc, 0x0 <repeats 82 times>, 0x7fea931cffbc, 0x0, 0x7fea931cffc0, 0x0 <repeats 71 times>}, data_stack = 0x7fea931fb688 "\377\377\377\377\377\377\377\377", data_stack_size = 2424, data_stack_base = 1712, repeat = 0x0, lower = 0x7febd7620852 <sre_lower_unicode>}
        status = 32746
        string = u'>=gnome-base/libbonobo-2.32::gentoo-haskell'
        start = 0
        end = 9223372036854775807
        kwlist = {0x7febd7660ad8 "pattern", 0x7febd7660cd9 "pos", 0x7febd7660cdd "endpos", 0x0}
#6  0x00007febd751ffcc in PyCFunction_Call (func=<built-in method match of _sre.SRE_Pattern object at remote 0x7feb2804ec58>, arg=(u'>=gnome-base/libbonobo-2.32::gentoo-haskell',), kw=0x0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Objects/methodobject.c:85
        f = 0x7feb37087fc8
        meth = 0x7febd76291f7 <pattern_match>
        self = <_sre.SRE_Pattern at remote 0x7feb2804ec58>
        size = -1282872823
#7  0x00007febd75c4b81 in call_function (pp_stack=0x7fff96f0e6d0, oparg=1) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Python/ceval.c:4021
        callargs = (u'>=gnome-base/libbonobo-2.32::gentoo-haskell',)
        flags = 3
        tstate = 0x7febd7bd1f58
        na = 1
        nk = 0
        n = 1
        pfunc = 0x7feb374ebf88
        func = <built-in method match of _sre.SRE_Pattern object at remote 0x7feb2804ec58>
        x = <_sre.SRE_Pattern at remote 0x7feb2804ec58>
        w = 0x0
#8  0x00007febd75bf6c6 in PyEval_EvalFrameEx (f=Frame 0x7feb374ebce8, for file /usr/lib64/portage/pym/portage/dep/__init__.py, line 1227, in __init__ (self=<Atom(blocker=False, eapi=None) at remote 0x7fea931d5fb0>, s=u'>=gnome-base/libbonobo-2.32::gentoo-haskell', unevaluated_atom=None, allow_wildcard=True, allow_repo=True, _use=None, eapi=None, is_valid_flag=None, eapi_attrs=<_eapi_attrs at remote 0x7feb31931f48>, atom_re=<_sre.SRE_Pattern at remote 0x7feb2804ec58>, blocker_prefix=u'', blocker=False), throwflag=0) at /mnt/1TB/var/tmp/portage/dev-lang/python-2.7.5-r2/work/Python-2.7.5/Python/ceval.c:2666
        sp = 0x7feb374ebf90
        stack_pointer = 0x7feb374ebf98
        next_instr = 0x7feb930726fd "}\f"
        opcode = 131
        oparg = 1
        why = WHY_NOT
        err = 0
        x = u'>=gnome-base/libbonobo-2.32::gentoo-haskell'
        v = <unknown at remote 0x83>
        w = 'match'
        u = False
        t = <unknown at remote 0x1>
        stream = 0x0
        fastlocals = 0x7feb374ebe70
        freevars = 0x7feb374ebf88
        retval = 0x0
        tstate = 0x7febd7bd1f58
        co = 0x7feb92e96f70
        instr_ub = -1
        instr_lb = 0
        instr_prev = -1

[cut]
msg196685 - (view) Author: Martin Mokrejs (mmokrejs) Date: 2013-08-31 22:28
To a naive user two places with numbers are in the stacktrace:

size = -1282872823

and
        instr_ub = -1
        instr_lb = 0
        instr_prev = -1
msg196686 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2013-08-31 22:46
This is a malloc() failure, not a Python bug ("DUMA Aborting: mprotect() failed: Cannot allocate memory").

Line 1173 in _sre.c allocates a fixed-sized structure (SRE_REPEAT):

            ctx->u.rep = (SRE_REPEAT*) PyObject_MALLOC(sizeof(*ctx->u.rep));

That structure is probably 32 bytes long in 64-bit mode.
msg196688 - (view) Author: Martin Mokrejs (mmokrejs) Date: 2013-08-31 23:16
I was actually printing every 10 seconds how much memory it was using, the last before got killed was:

  PID    VSZ   RSS     TIME     ELAPSED %CPU %MEM COMMAND
 4097 4938188 2445712 00:22:44    25:04 90.7 15.0 /usr/bin/python2.7 /usr/bin/emerge dev-lang/python:2.7

Provided I have 16GB RAM then maybe it was really some limit in the Bourne shell or OS which prevented DUMA to obtain more memory. But my own python-based app can can grow to even 12GB RSS on this computer so I wonder what limit would be the cause. Probably some overhead due to DUMA.



I increased shell limits and looks it can continue further so far:

vostro crashtest # ulimit -l unlimited
vostro crashtest # ulimit -s unlimited
vostro crashtest # ulimit -i unlimited
vostro crashtest # 
vostro crashtest # ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) unlimited
max locked memory       (kbytes, -l) unlimited
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) unlimited
cpu time               (seconds, -t) unlimited
max user processes              (-u) 127104
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited
#


Currently the emerge through DUMA is at:

  PID    VSZ   RSS     TIME     ELAPSED %CPU %MEM COMMAND
 9528 6121764 3041960 00:34:16    56:05 61.1 18.6 /usr/bin/python2.7 /usr/bin/emerge dev-lang/python:2.7

and still continues ...


Sorry, should better read the main STDERR output before diving into gdb stacktraces. I thought those negative numbers are a true sign of an error. ;)
msg196689 - (view) Author: Tim Peters (tim.peters) * (Python committer) Date: 2013-08-31 23:25
Note this line in your first post:

    DUMA Aborting: mprotect() failed: Cannot allocate memory.

Python never calls mprotect(), but DUMA() probably does.  Also note what it said after that:

   Check README section 'MEMORY USAGE AND EXECUTION SPEED'
   if your (Linux) system may limit the number of different page
   mappings per process

That is, it may be a limitation of your kernel.

In any case, there's no Python issue here, so closing this.
msg204955 - (view) Author: Martin Mokrejs (mmokrejs) Date: 2013-12-01 20:22
The issue could have been caused the malfunctioning memory or CPU.
http://bugs.python.org/issue18843#msg204954
History
Date User Action Args
2013-12-01 20:22:29mmokrejssetmessages: + msg204955
2013-08-31 23:25:16tim.peterssetnosy: + tim.peters

messages: + msg196689
stage: resolved
2013-08-31 23:16:37mmokrejssetmessages: + msg196688
2013-08-31 22:46:16pitrousetstatus: open -> closed

nosy: + vstinner, pitrou
messages: + msg196686

resolution: not a bug
2013-08-31 22:28:16mmokrejssetmessages: + msg196685
2013-08-31 22:26:14mmokrejscreate