Skip to content

Segfaults with pymssql==2.1.2 on linux with bundled freetds #406

New issue
New issue
Open
#412
Open
Segfaults with pymssql==2.1.2 on linux with bundled freetds#406
#412
Milestone
2.2.0
@pupssman

Description

@pupssman
pupssman
opened on Feb 26, 2016

Hello, fellow pymssql people!

I've recently started updating some internal tooling to use pymssql==2.1.2 (from 2.1.1) and discovered that it causes segmentation faults in test suites. I have not yet determined exact sequence of operations that leads to the segfault, but I've got a reproducible (yet not disclosable) way to trigger it.

My environment is as follows:

ubuntu 14.04 docker container
python==2.7.5-5ubuntu3
pymssql==2.1.2 installed with `PYMSSQL_BUILD_WITH_BUNDLED_FREETDS=1`
SQLAlchemy==1.0.12

gdb's trace of segfault is:

test/test_database.py::test_context_gets_rolled_back[sqlite] [09:43:47.208] verba  database.py:126     INFO: Creating metadata table...
[09:43:47.248] verba  database.py:128     INFO: Done

Program received signal SIGSEGV, Segmentation fault.
_int_malloc (av=0x7ffff7bb5760 <main_arena>, bytes=768) at malloc.c:3489
3489    malloc.c: No such file or directory.
(gdb) bt
#0  _int_malloc (av=0x7ffff7bb5760 <main_arena>, bytes=768) at malloc.c:3489
#1  0x00007ffff78797b0 in __GI___libc_malloc (bytes=768) at malloc.c:2891
#2  0x0000000000535b3a in dictresize.18440 (mp=mp@entry=0x7ffff0a656e0, minused=<optimized out>)
    at ../Objects/dictobject.c:643
#3  0x00000000004ad525 in dict_set_item_by_hash_or_entry (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    ep=0x0, hash=<optimized out>, key='pathname', 
    op={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}) at ../Objects/dictobject.c:788
#4  PyDict_SetItem (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', key='pathname', 
    op={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}) at ../Objects/dictobject.c:818
#5  _PyObject_GenericSetAttrWithDict (
    obj=obj@entry=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 
    name=name@entry='pathname', value=value@entry='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    dict={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}, dict@entry=0x0)
    at ../Objects/object.c:1529
#6  0x00000000004ad9dd in PyObject_GenericSetAttr (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    name='pathname', 
    obj=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>)
    at ../Objects/object.c:1559
#7  PyObject_SetAttr (
    v=v@entry=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 
    name='pathname', value=value@entry='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py') at ../Objects/object.c:1247
#8  0x000000000049a356 in PyEval_EvalFrameEx (
    f=f@entry=Frame 0x14375f0, for file /usr/lib/python2.7/logging/__init__.py, line 268, in __init__ (self=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, name='sqlalchemy.pool.QueuePool', level=40, pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', lineno=643, msg='Exception during reset or similar', args=(...), exc_info=(<type at remote 0x7ffff236bc80>, _mssql.MSSQLDatabaseException((20006, '\xa0\x9d\xc4DB-Lib error message 20006, severity 9:\nWrite to the server failed\n'),), <traceback at remote 0x7ffff0a681b8>), func='_finalize_fairy', ct=<float at remote 0x1425130>), throwflag=throwflag@entry=0) at ../Python/ceval.c:2004
#9  0x00000000004a1c9a in PyEval_EvalCodeEx (closure=<optimized out>, defcount=<optimized out>, defs=0x7ffff5749e68, 
    kwcount=<optimized out>, kws=<optimized out>, argcount=21198320, args=<optimized out>, locals=0x0, 
    globals=<optimized out>, co=<optimized out>) at ../Python/ceval.c:3252
#10 function_call.15337 (func=func@entry=<function at remote 0x7ffff54c59b0>, 
    arg=arg@entry=(<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 'sqlalchemy.pool.QueuePool', 40, 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 643, 'Exception during reset or similar', (...), (<type at remote 0x7ffff236bc80>, _mssql.MSSQLDatabaseException((20006, '\xa0\x9d\xc4DB-Lib error message 20006, severity 9:\nWrite to the server failed\n'),), <traceback at remote 0x7ffff0a681b8>), '_finalize_fairy'), 
    kw=kw@entry=0x0) at ../Objects/funcobject.c:526
#11 0x00000000004dfe94 in PyObject_Call (kw=0x0, 
    arg=(<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 'sqlalchemy.pool.QueuePool', 40, 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 643, 'Exception during reset or similar', (...),---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) py
py-bt               py-list             py-print            python              
py-down             py-locals           py-up               python-interactive  
(gdb) py-bt
#8 Frame 0x14375f0, for file /usr/lib/python2.7/logging/__init__.py, line 268, in __init__ (self=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, name='sqlalchemy.pool.QueuePool', level=40, pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', lineno=643, msg='Exception during reset or similar', args=(...), exc_info=(<type at remote 0x7ffff236bc80>, _mssql.MSSQLDatabaseException((20006, '\xa0\x9d\xc4DB-Lib error message 20006, severity 9:\nWrite to the server failed\n'),), <traceback at remote 0x7ffff0a681b8>), func='_finalize_fairy', ct=<float at remote 0x1425130>)
    self.pathname = pathname
#19 Frame 0x14373a0, for file /usr/lib/python2.7/logging/__init__.py, line 1244, in makeRecord (self=<Logger(name='sqlalchemy.pool.QueuePool', parent=<Logger(name='sqlalchemy', parent=<RootLogger(name='root', parent=None, handlers=[], level=30, disabled=0, propagate=1, filters=[]) at remote 0x7ffff54d9410>, handlers=[], level=30, disabled=0, manager=<Manager(emittedNoHandlerWarning=0, disable=0, root=<...>, loggerDict={'sqlalchemy.orm.strategies': <PlaceHolder(loggerMap={<Logger(name='sqlalchemy.orm.strategies.SubqueryLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ce10>: None, <Logger(name='sqlalchemy.orm.strategies.JoinedLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff2726050>: None, <Logger(name='sqlalchemy.orm.strategies.LazyLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ca90>: None, <Logger(name='sqlalchemy...(truncated)
    rv = LogRecord(name, level, fn, lno, msg, args, exc_info, func)
#23 Frame 0x13e7570, for file /usr/lib/python2.7/logging/__init__.py, line 1270, in _log (self=<Logger(name='sqlalchemy.pool.QueuePool', parent=<Logger(name='sqlalchemy', parent=<RootLogger(name='root', parent=None, handlers=[], level=30, disabled=0, propagate=1, filters=[]) at remote 0x7ffff54d9410>, handlers=[], level=30, disabled=0, manager=<Manager(emittedNoHandlerWarning=0, disable=0, root=<...>, loggerDict={'sqlalchemy.orm.strategies': <PlaceHolder(loggerMap={<Logger(name='sqlalchemy.orm.strategies.SubqueryLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ce10>: None, <Logger(name='sqlalchemy.orm.strategies.JoinedLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff2726050>: None, <Logger(name='sqlalchemy.orm.strategies.LazyLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ca90>: None, <Logger(name='sqlalchemy.orm.s...(truncated)
    record = self.makeRecord(self.name, level, fn, lno, msg, args, exc_info, func, extra)
#28 Frame 0xbe4c70, for file /usr/lib/python2.7/logging/__init__.py, line 1178, in error (self=<Logger(name='sqlalchemy.pool.QueuePool', parent=<Logger(name='sqlalchemy', parent=<RootLogger(name='root', parent=None, handlers=[], level=30, disabled=0, propagate=1, filters=[]) at remote 0x7ffff54d9410>, handlers=[], level=30, disabled=0, manager=<Manager(emittedNoHandlerWarning=0, disable=0, root=<...>, loggerDict={'sqlalchemy.orm.strategies': <PlaceHolder(loggerMap={<Logger(name='sqlalchemy.orm.strategies.SubqueryLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ce10>: None, <Logger(name='sqlalchemy.orm.strategies.JoinedLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff2726050>: None, <Logger(name='sqlalchemy.orm.strategies.LazyLoader', parent=<...>, handlers=[], level=0, disabled=0, manager=<...>, propagate=1, filters=[]) at remote 0x7ffff271ca90>: None, <Logger(name='sqlalchemy.orm.s...(truncated)
    self._log(ERROR, msg, args, **kwargs)
#32 Frame 0x13e5830, for file build/bdist.linux-x86_64/egg/sqlalchemy/pool.py, line 643, in _finalize_fairy (connection=<pymssql.Connection at remote 0x7ffff0abb290>, connection_record=<_ConnectionRecord(finalize_callback=<collections.deque at remote 0x7ffff0abd6e0>, connection=<pymssql.Connection at remote 0x7ffff0abb290>, _ConnectionRecord__pool=<QueuePool(_recycle=-1, _invoke_creator=<function at remote 0x7ffff0a95ed8>, _overflow=-4, _overflow_lock=<thread.lock at remote 0x7ffff275d9d0>, _pool=<Queue(queue=<collections.deque at remote 0x7ffff0abd8a0>, not_empty=<_Condition(_Condition__lock=<_RLock(_Verbose__verbose=False, _RLock__owner=None, _RLock__block=<thread.lock at remote 0x7ffff275d8d0>, _RLock__count=0) at remote 0x7ffff0aa0210>, acquire=<instancemethod at remote 0x7ffff0aab500>, _is_owned=<instancemethod at remote 0x7ffff0aab7d0>, _release_save=<instancemethod at remote 0x7ffff0a92550>, release=<instancemethod at remote 0x7ffff0aab320>, _acquire_restore=<instancemethod at remote 0x7ffff0a92460>, _Verb...(truncated)
Python Exception <class 'FileNotFoundError'> [Errno 2] No such file or directory: 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py': 
Error occurred in Python command: [Errno 2] No such file or directory: 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py'
(gdb) py
py-bt               py-list             py-print            python              
py-down             py-locals           py-up               python-interactive  
(gdb) py-list
 263            if args and len(args) == 1 and isinstance(args[0], dict) and args[0]:
 264                args = args[0]
 265            self.args = args
 266            self.levelname = getLevelName(level)
 267            self.levelno = level
>268            self.pathname = pathname
 269            try:
 270                self.filename = os.path.basename(pathname)
 271                self.module = os.path.splitext(self.filename)[0]
 272            except (TypeError, ValueError, AttributeError):
 273                self.filename = pathname
(gdb) bt
#0  _int_malloc (av=0x7ffff7bb5760 <main_arena>, bytes=768) at malloc.c:3489
#1  0x00007ffff78797b0 in __GI___libc_malloc (bytes=768) at malloc.c:2891
#2  0x0000000000535b3a in dictresize.18440 (mp=mp@entry=0x7ffff0a656e0, minused=<optimized out>)
    at ../Objects/dictobject.c:643
#3  0x00000000004ad525 in dict_set_item_by_hash_or_entry (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    ep=0x0, hash=<optimized out>, key='pathname', 
    op={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}) at ../Objects/dictobject.c:788
#4  PyDict_SetItem (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', key='pathname', 
    op={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}) at ../Objects/dictobject.c:818
#5  _PyObject_GenericSetAttrWithDict (
    obj=obj@entry=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 
    name=name@entry='pathname', value=value@entry='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    dict={'msg': 'Exception during reset or similar', 'levelno': 40, 'args': (), 'pathname': 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 'name': 'sqlalchemy.pool.QueuePool', 'levelname': 'ERROR'}, dict@entry=0x0)
    at ../Objects/object.c:1529
#6  0x00000000004ad9dd in PyObject_GenericSetAttr (value='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 
    name='pathname', 
    obj=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>)
    at ../Objects/object.c:1559
#7  PyObject_SetAttr (
    v=v@entry=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 
    name='pathname', value=value@entry='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py') at ../Objects/object.c:1247
#8  0x000000000049a356 in PyEval_EvalFrameEx (
    f=f@entry=Frame 0x14375f0, for file /usr/lib/python2.7/logging/__init__.py, line 268, in __init__ (self=<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, name='sqlalchemy.pool.QueuePool', level=40, pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', lineno=643, msg='Exception during reset or similar', args=(...), exc_info=(<type at remote 0x7ffff236bc80>, _mssql.MSSQLDatabaseException((20006, '\xa0\x9d\xc4DB-Lib error message 20006, severity 9:\nWrite to the server failed\n'),), <traceback at remote 0x7ffff0a681b8>), func='_finalize_fairy', ct=<float at remote 0x1425130>), throwflag=throwflag@entry=0) at ../Python/ceval.c:2004
#9  0x00000000004a1c9a in PyEval_EvalCodeEx (closure=<optimized out>, defcount=<optimized out>, defs=0x7ffff5749e68, 
    kwcount=<optimized out>, kws=<optimized out>, argcount=21198320, args=<optimized out>, locals=0x0, 
    globals=<optimized out>, co=<optimized out>) at ../Python/ceval.c:3252
#10 function_call.15337 (func=func@entry=<function at remote 0x7ffff54c59b0>, 
    arg=arg@entry=(<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 'sqlalchemy.pool.QueuePool', 40, 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 643, 'Exception during reset or similar', (...), (<type at remote 0x7ffff236bc80>, _mssql.MSSQLDatabaseException((20006, '\xa0\x9d\xc4DB-Lib error message 20006, severity 9:\nWrite to the server failed\n'),), <traceback at remote 0x7ffff0a681b8>), '_finalize_fairy'), 
    kw=kw@entry=0x0) at ../Objects/funcobject.c:526
#11 0x00000000004dfe94 in PyObject_Call (kw=0x0, 
    arg=(<LogRecord(msg='Exception during reset or similar', levelno=40, args=(), pathname='build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', name='sqlalchemy.pool.QueuePool', levelname='ERROR') at remote 0x7ffff0a644d0>, 'sqlalchemy.pool.QueuePool', 40, 'build/bdist.linux-x86_64/egg/sqlalchemy/pool.py', 643, 'Exception during reset or similar', (...),---Type <return> to continue, or q <return> to quit---q
Quit
(gdb) generate-core-file 
warning: target file /proc/1153/cmdline contained unexpected null characters
Saved corefile core.1153
(gdb)

I can't attach the dump file directly here (its over 10 MB), but can attach it elsewhere or email to someone.

Interesting part is that when installing pymssql without PYMSSQL_BUILD_WITH_BUNDLED_FREETDS it works OK. Freetds used in that installation (on same machine) is:

root@9201777d8cca:/test# dpkg -l | grep tds
ii  freetds-common                  0.91-5                           all          configuration files for FreeTDS SQL client libraries
ii  freetds-dev                     0.91-5                           amd64        MS SQL and Sybase client library (static libs and headers)

From my point of view it looks like pymssql is somehow corrupting the memory of host python process and that causes errors later on in the program.

I would gladly collect any extra info on the crash dump if given proper instructions.

Hope for the best and thanks for your time in advance)

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions