[ZODB-Dev] Same transaction object (re)-used for subsequent requests?

[Andreas Jung]

Hi,

I encountered the following strange behavior with Zope 2.8.8.

The following code is used to integrate SQLAlchemy with
Zope. A registered utility subclassing ZopeBaseWrapper provides
a 'connection' property. This property should always return
for a given transaction the same sqlalchemy.Connection object
(which is like a connection from a connection pool within a DA).

Within a thread-local cache the last id of the transaction and the last 
connection is stored in order to return the connection from the cache if 
the property 'connection' is called/used multiple times within one 
request/one
transaction.

A ConnectionDataManger instance is added a data manager to the current
transaction in order to integrate the ZODB transaction with the transaction 
system by SQLAlchemy.


class ConnectionDataManager(object):
    """ Wraps connection into transaction context of Zope """

    implements(IDataManager)

    def __init__(self, connection):
        self.connection = connection
        self.transaction = connection.begin()

    def tpc_begin(self, trans):
        log('tpc_begin() - %s' % trans)
        pass

    def abort(self, trans):
        self.transaction.rollback()
        self.connection.close()
        self.connection = None
        log('abort() - %s' % trans)

    def commit(self, trans):
        self.transaction.commit()
        log('commit() - %s' % trans)
        self.connection.close()
        self.connection = None

    def tpc_vote(self, trans):
        pass

    def tpc_finish(self, trans):
        log('tcp_finish() - %s' % trans)
        pass

    def tpc_abort(self, trans):
        log('tcp_abort() - %s' % trans)
        pass

    def sortKey(self):
        return str(id(self))

_connection_cache = threading.local() # module-level cache

class ZopeBaseWrapper(BaseWrapper):

    @property
    def connection(self):

        if not hasattr(_connection_cache, 'last_connection'):
            _connection_cache.last_transaction = None
            _connection_cache.last_connection = None

        # get current transaction
        txn = transaction.get()
        txn_str = str(txn)
        log('current thread - %s' % threading.currentThread())
        log('checking for transaction - %s' % txn_str)

        # return cached connection if we are within the same transaction
        # and same thread
        if txn_str == _connection_cache.last_transaction:
            log('returning cached connection - %s' % 
_connection_cache.last_connection)
            return _connection_cache.last_connection

        # no cached connection, let's create a new one
        connection = self.engine.connect()
        log('creating new connection - %s' % connection)

        # register a DataManager with the current transaction
        txn.join(ConnectionDataManager(connection))

        # update thread-local cache
        _connection_cache.last_transaction = txn_str
        _connection_cache.last_connection = connection

        # return the connection
        return connection

This works almost. However when I hammer my Zope instance using ab2 
(without concurrent request, option -c 1) then in some rare cases I see 
that a new request uses a formerly used transaction object. Look at the 
output

Request #1:
*** <_DummyThread(Dummy-1, started daemon)> - current thread - 
<_DummyThread(Dummy-1, started daemon)>
*** <_DummyThread(Dummy-1, started daemon)> - checking for transaction - 
<transaction._transaction.Transaction object at 0x2ba7b29e7050>
*** <_DummyThread(Dummy-1, started daemon)> - creating new connection - 
<sqlalchemy.engine.base.Connection object at 0x2ba7b29c4b90>
*** <_DummyThread(Dummy-1, started daemon)> - tpc_begin() - 
<transaction._transaction.Transaction object at 0x2ba7b29e7050>
*** <_DummyThread(Dummy-1, started daemon)> - commit() - 
<transaction._transaction.Transaction object at 0x2ba7b29e7050>
*** <_DummyThread(Dummy-1, started daemon)> - tcp_finish() - 
<transaction._transaction.Transaction object at 0x2ba7b29e7050>

Request #2:
*** <_DummyThread(Dummy-1, started daemon)> - current thread - 
<_DummyThread(Dummy-1, started daemon)>
*** <_DummyThread(Dummy-1, started daemon)> - checking for transaction - 
<transaction._transaction.Transaction object at 0x2ba7b29e7050>
*** <_DummyThread(Dummy-1, started daemon)> - returning cached connection - 
<sqlalchemy.engine.base.Connection object at 0x2ba7b29c4b90>

As you can see request #1 commits without a problem. But for the second 
request handled by the same thread the same transaction object is re-used.

Bug or feature?

Andreas

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 186 bytes
Desc: not available
Url : http://mail.zope.org/pipermail/zodb-dev/attachments/20070501/406dc03a/attachment.bin