Buffer instance error while commiting (python2.7)

[marplatense]

While trying to use transaction.manager as context manager, I hit a buffer instance error with traceback (this is reproducible just by issuing a transaction.commit, too):

Here is a complete example (requires sqlalchemy -reproducible at least with 0.9.4 and 0.7.8), zope-sqlalchemy and transaction:

from sqlalchemy import MetaData, Column, Integer, create_engine
from sqlalchemy.ext.declarative import declarative_base
from sqlalchemy.orm import scoped_session, sessionmaker
import transaction
from zope.sqlalchemy import ZopeTransactionExtension
S = scoped_session(sessionmaker(extension=ZopeTransactionExtension()))
M = MetaData()
B = declarative_base(metadata=M)
engine = create_engine('sqlite:///:memory:', echo=True)
S.configure(bind=engine)
M.bind = engine
class Example(B):
    __tablename__ = "example"
    id = Column(Integer, primary_key=True)
    calc = Column(Integer)
M.create_all(engine)
with transaction.manager:
    S.add_all([Example(id=1, calc=10), Example(id=1, calc=11)])

As you can see, we are trying to insert the same id in a primary key column, something that has to raise an error and it does:

---------------------------------------------------------------------------
TypeError                                 Traceback (most recent call last)
<ipython-input-14-de8e5b3d6d89> in <module>()
      1 with transaction.manager:
----> 2         S.add_all([Example(id=1, calc=10), Example(id=1, calc=11)])
      3 

/home/mariano/Code/SmD/env/local/lib/python2.7/site-packages/transaction-1.4.3-py2.7.egg/transaction/_manager.pyc in __exit__(self, t, v, tb)
    118     def __exit__(self, t, v, tb):
    119         if v is None:
--> 120             self.commit()
    121         else:
    122             self.abort()

/home/mariano/Code/SmD/env/local/lib/python2.7/site-packages/transaction-1.4.3-py2.7.egg/transaction/_manager.pyc in commit(self)
    109         """ See ITransactionManager.
    110         """
--> 111         return self.get().commit()
    112 
    113     def abort(self):

/home/mariano/Code/SmD/env/local/lib/python2.7/site-packages/transaction-1.4.3-py2.7.egg/transaction/_transaction.pyc in commit(self)
    276             tb = None
    277             try:
--> 278                 t, v, tb = self._saveAndGetCommitishError()
    279                 self._callAfterCommitHooks(status=False)
    280                 reraise(t, v, tb)

/home/mariano/Code/SmD/env/local/lib/python2.7/site-packages/transaction-1.4.3-py2.7.egg/transaction/_transaction.pyc in _saveAndGetCommitishError(self)
    298             t, v, tb = sys.exc_info()
    299             # Record how we got into commit().
--> 300             traceback.print_stack(sys._getframe(1), None, ft)
    301             # Append the stack entries from here down to the exception.
    302             traceback.print_tb(tb, None, ft)

/usr/lib/python2.7/traceback.pyc in print_stack(f, limit, file)
    267         except ZeroDivisionError:
    268             f = sys.exc_info()[2].tb_frame.f_back
--> 269     print_list(extract_stack(f, limit), file)
    270 
    271 def format_stack(f=None, limit=None):

/usr/lib/python2.7/traceback.pyc in print_list(extracted_list, file)
     23                '  File "%s", line %d, in %s' % (filename,lineno,name))
     24         if line:
---> 25             _print(file, '    %s' % line.strip())
     26 
     27 def format_list(extracted_list):

/usr/lib/python2.7/traceback.pyc in _print(file, str, terminator)
     11 
     12 def _print(file, str='', terminator='\n'):
---> 13     file.write(str+terminator)
     14 
     15 

TypeError: 'unicode' does not have the buffer interface

[tseaver]

Ouch! Can you please just post the "normal" traceback next time -- that "expanded view" makes finding things really hard.

I cannot reproduce the buffer error locally:

$ /opt/Python-2.6.9/bin/virtualenv --no-pip /tmp/mariano
...
$ cd /tmp/mariano/
$ bin/easy_install zope.sqlalchemy
...
$ cat > issue_5.py
from sqlalchemy import MetaData, Column, Integer, create_engine
from sqlalchemy.ext.declarative import declarative_base
from sqlalchemy.orm import scoped_session, sessionmaker
import transaction
from zope.sqlalchemy import ZopeTransactionExtension
S = scoped_session(sessionmaker(extension=ZopeTransactionExtension()))
M = MetaData()
B = declarative_base(metadata=M)
engine = create_engine('sqlite:///:memory:', echo=True)
S.configure(bind=engine)
M.bind = engine
class Example(B):
    __tablename__ = "example"
    id = Column(Integer, primary_key=True)
    calc = Column(Integer)
M.create_all(engine)
with transaction.manager:
    S.add_all([Example(id=1, calc=10), Example(id=1, calc=11)])
$ bin/python issue_5.py 
2014-04-04 12:00:37,108 INFO sqlalchemy.engine.base.Engine SELECT CAST('test plain returns' AS VARCHAR(60)) AS anon_1
2014-04-04 12:00:37,108 INFO sqlalchemy.engine.base.Engine ()
2014-04-04 12:00:37,109 INFO sqlalchemy.engine.base.Engine SELECT CAST('test unicode returns' AS VARCHAR(60)) AS anon_1
2014-04-04 12:00:37,109 INFO sqlalchemy.engine.base.Engine ()
2014-04-04 12:00:37,110 INFO sqlalchemy.engine.base.Engine PRAGMA table_info("example")
2014-04-04 12:00:37,110 INFO sqlalchemy.engine.base.Engine ()
2014-04-04 12:00:37,111 INFO sqlalchemy.engine.base.Engine 
CREATE TABLE example (
    id INTEGER NOT NULL, 
    calc INTEGER, 
    PRIMARY KEY (id)
)

2014-04-04 12:00:37,111 INFO sqlalchemy.engine.base.Engine ()
2014-04-04 12:00:37,113 INFO sqlalchemy.engine.base.Engine COMMIT
2014-04-04 12:00:37,115 INFO sqlalchemy.engine.base.Engine BEGIN (implicit)
2014-04-04 12:00:37,116 INFO sqlalchemy.engine.base.Engine INSERT INTO example (id, calc) VALUES (?, ?)
2014-04-04 12:00:37,116 INFO sqlalchemy.engine.base.Engine ((1, 10), (1, 11))
2014-04-04 12:00:37,117 INFO sqlalchemy.engine.base.Engine ROLLBACK
Traceback (most recent call last):
File "issue_5.py", line 18, in <module>
    S.add_all([Example(id=1, calc=10), Example(id=1, calc=11)])
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_manager.py", line 120, in __exit__
    self.commit()
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_manager.py", line 111, in commit
    return self.get().commit()
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_transaction.py", line 280, in commit
    reraise(t, v, tb)
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_transaction.py", line 271, in commit
    self._commitResources()
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_transaction.py", line 417, in _commitResources
    reraise(t, v, tb)
File "/tmp/mariano/lib/python2.6/site-packages/transaction-1.4.3-py2.6.egg/transaction/_transaction.py", line 389, in _commitResources
    rm.tpc_begin(self)
File "/tmp/mariano/lib/python2.6/site-packages/zope.sqlalchemy-0.7.4-py2.6.egg/zope/sqlalchemy/datamanager.py", line 90, in tpc_begin
    self.session.flush()
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1903, in flush
    self._flush(objects)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 2021, in _flush
    transaction.rollback(_capture_exception=True)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/util/langhelpers.py", line 57, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/session.py", line 1985, in _flush
    flush_context.execute()
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 370, in execute
    rec.execute(self)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/unitofwork.py", line 523, in execute
    uow
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 64, in save_obj
    mapper, table, insert)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/orm/persistence.py", line 562, in _emit_insert_statements
    execute(statement, multiparams)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 720, in execute
    return meth(self, multiparams, params)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/sql/elements.py", line 317, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 817, in _execute_clauseelement
    compiled_sql, distilled_params
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 947, in _execute_context
    context)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 1108, in _handle_dbapi_exception
    exc_info
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/util/compat.py", line 185, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/base.py", line 917, in _execute_context
    context)
File "/tmp/mariano/lib/python2.6/site-packages/SQLAlchemy-0.9.4-py2.6-linux-x86_64.egg/sqlalchemy/engine/default.py", line 432, in do_executemany
    cursor.executemany(statement, parameters)
sqlalchemy.exc.IntegrityError: (IntegrityError) PRIMARY KEY must be unique u'INSERT INTO example (id, calc) VALUES (?, ?)' ((1, 10), (1, 11))

which is just what I would expect. Is there something different about your environment?

[tseaver]

I wondered about Py3k, but I see the same result with a 3.3.3 virtualenv.

[marplatense]

Sorry about the expanded traceback, won't happen again. I can reproduce the issue with python2.7 (I couldn't build 2.6 in my machine due to _sqlite3 not building) so I could not confirm.

[tseaver]

I cannot reproduce here with a Python 2.7.6 virtualenv either.

[marplatense]

Looks I am running 2.7.4: I better upgrade and retry, sorry for wasting your time and thanks for the answer.

[tseaver]

Feel free to re-open if you can find a way to reproduce the issue.

[marplatense]

For completeness, I compiled from source 2.7.6 and reinstalled all packages and I still get the error. It beats me why it happens but -as you said- if I find a way to reproduce, I re-open the bug.

[mgedmin]

The original traceback complained about unicode objects. While printing source code lines from traceback.py. I don't quite see how you can get into that situation on Python 2.7. Maybe ipython monkey-patches something? I'd love to play with this error using pdb.pm(), if you can manage to reproduce it.

I don't think the transaction package has anything to do with this. You just got a 2nd error while you happened to be printing the traceback for a legitimate SQL error that happened during transaction commit.

[marplatense]

You are 100% right Marius: I ran the example with regular python console and the real error surfaced. So the problem has something to do with ipython. Thanks for the tip and once again sorry for wasting everyone's time with an unrelated bug.

[kelp404]

@mgedmin It is transaction problem. https://github.com/zopefoundation/transaction/blob/master/transaction/_compat.py#L41

I think the result of sql server error message is utf-8 string not binary.

The way to fix:

import StringIO
import transaction._transaction
transaction._transaction.StringIO = StringIO.StringIO

https://bugs.launchpad.net/zodb/+bug/1073651

BytesIO vs StringIO in Python 2.7

In Python 2.x, "string" means "bytes", and "unicode" means "string". You should use the StringIO or cStringIO modules. The mode will depend on which kind of data you pass in as the buffer parameter.

http://stackoverflow.com/questions/1279244/bytesio-with-python-v2-5

[mgedmin]

The traceback indicates it's not the server error message but rather a line of source code that is a Unicode string. And I think everyone who complains about this also mentions using ipython.

I think it's worth fixing in transaction: ipython is nice, and even if I'm right about it stuffing unexpected Unicode objects into the linecache module, why should we take it out on users?

It'd be nice if the developers had a way of reproducing the error. Perhaps it would be enough to run the reproducer script with ipython instead of python?

[mmerickel]

This happens all the time for me on IPython. I can't said it's ever happened elsewhere.

[mgedmin]

Do you have a way for us to reproduce this?

[davidjb]

Seen happening for me with Python 2.7.5 (RHEL 7.4 package managed) within an ipython 3.2.1 shell. I was attempting to transaction.commit() after making changes to a sqlalchemy session.

Digging into the problem a bit more, my buffer error was caused because traceback._print was called with a str argument of u' transaction.commit()', being the last line run in ipython. So perhaps ipython does something different with its framing (eg sys._getframe at https://github.com/zopefoundation/transaction/blob/master/transaction/_transaction.py#L330).

In any case, using @kelp404's workaround solves the issue in the ipython session which is fine as I'm only temporarily debugging.

[mgedmin]

Steps to reproduce:

$ pip install ipython transaction
$ ipython
In [1]: import transaction

In [2]: from transaction.tests.examples import ResourceManager

In [3]: rm = ResourceManager()

In [4]: def crash(*a, **kw):
   ...:     raise Exception('Boo!')
   ...: 

In [5]: rm.tpc_vote = crash

In [6]: with transaction.manager as txn:
   ...:     txn.join(rm)
   ...:     

At the point of crash we're trying to write u' txn.join(rm)' into a <_io.BytesIO object at 0x7fb0da944110>. If we were using cStringIO.StringIO() on Python 2.7, we wouldn't crash (as long as the unicode source line has only ASCII characters in it).

(I'm pretty sure this bug doesn't show up on Python 3 where source lines are always unicode and we use an io.StringIO()).

[mgedmin]

TBH I'm not sure we can fix this 100% -- a StringIO() doesn't like Unicode strings with non-ASCII characters. We either use our own StringIO wrapper that decodes Unicode to UTF-8, or we ask IPython to fix their bug (stuffing Unicode strings into linecache).

Here's how to reproduce the same problem using only ipython and the standard library:

$ ipython
In [1]: from cStringIO import StringIO

In [2]: s = StringIO()

In [3]: try:
   ...:     raise Exception('ąčę')
   ...: except:
   ...:     traceback.print_exc(file=s)
   ...:     
---------------------------------------------------------------------------
UnicodeEncodeError                        Traceback (most recent call last)
<ipython-input-5-42fce313b810> in <module>()
      2     raise Exception('ąčę')
      3 except:
----> 4     traceback.print_exc(file=s)
      5 

/usr/lib/python2.7/traceback.pyc in print_exc(limit, file)
    231     try:
    232         etype, value, tb = sys.exc_info()
--> 233         print_exception(etype, value, tb, limit, file)
    234     finally:
    235         etype = value = tb = None

/usr/lib/python2.7/traceback.pyc in print_exception(etype, value, tb, limit, file)
    123     if tb:
    124         _print(file, 'Traceback (most recent call last):')
--> 125         print_tb(tb, limit, file)
    126     lines = format_exception_only(etype, value)
    127     for line in lines:

/usr/lib/python2.7/traceback.pyc in print_tb(tb, limit, file)
     68         linecache.checkcache(filename)
     69         line = linecache.getline(filename, lineno, f.f_globals)
---> 70         if line: _print(file, '    ' + line.strip())
     71         tb = tb.tb_next
     72         n = n+1

/usr/lib/python2.7/traceback.pyc in _print(file, str, terminator)
     11 
     12 def _print(file, str='', terminator='\n'):
---> 13     file.write(str+terminator)
     14 
     15 

UnicodeEncodeError: 'ascii' codec can't encode characters in position 21-23: ordinal not in range(128)

[rouge8]

FWIW, it looks like the IPython suggestion is to implement a StringIO wrapper: https://github.com/ipython/ipython/issues/9126#issuecomment-174966638