PublicArchive/sqlalchemy
2
0
Fork 0
mirror of https://github.com/sqlalchemy/sqlalchemy.git synced 2026-06-02 13:59:02 -04:00
Code Issues Packages Projects Releases Wiki Activity

Merge branch 'master' into ticket_3100

Browse Source
This commit is contained in:
Mike Bayer
2014-08-20 13:43:22 -04:00
parent fcea5c86d3 92b0ad0fef
commit d233bb3fc9
4 changed files with 119 additions and 37 deletions
Download Patch File Download Diff File Expand all files Collapse all files
doc/build/changelog/changelog_09.rst
Vendored
+11
View File
@@ -13,6 +13,17 @@
.. changelog::
:version: 0.9.8
.. change::
:tags: bug, pool
:versions: 1.0.0
:tickets: 3168
Fixed bug in connection pool logging where the "connection checked out"
debug logging message would not emit if the logging were set up using
``logging.setLevel()``, rather than using the ``echo_pool`` flag.
Tests to assert this logging have been added. This is a
regression that was introduced in 0.9.0.
.. change::
:tags: feature, postgresql, pg8000
:versions: 1.0.0
lib/sqlalchemy/pool.py
+12 -10
View File
@@ -443,16 +443,17 @@ class _ConnectionRecord(object):
except:
rec.checkin()
raise
fairy = _ConnectionFairy(dbapi_connection, rec)
echo = pool._should_log_debug()
fairy = _ConnectionFairy(dbapi_connection, rec, echo)
rec.fairy_ref = weakref.ref(
fairy,
lambda ref: _finalize_fairy and
_finalize_fairy(
dbapi_connection,
rec, pool, ref, pool._echo)
rec, pool, ref, echo)
)
_refs.add(rec)
if pool._echo:
if echo:
pool.logger.debug("Connection %r checked out from pool",
dbapi_connection)
return fairy
@@ -560,9 +561,10 @@ def _finalize_fairy(connection, connection_record,
connection)
try:
fairy = fairy or _ConnectionFairy(connection, connection_record)
fairy = fairy or _ConnectionFairy(
connection, connection_record, echo)
assert fairy.connection is connection
fairy._reset(pool, echo)
fairy._reset(pool)
# Immediately close detached instances
if not connection_record:
@@ -603,9 +605,10 @@ class _ConnectionFairy(object):
"""
def __init__(self, dbapi_connection, connection_record):
def __init__(self, dbapi_connection, connection_record, echo):
self.connection = dbapi_connection
self._connection_record = connection_record
self._echo = echo
connection = None
"""A reference to the actual DBAPI connection being tracked."""
@@ -642,7 +645,6 @@ class _ConnectionFairy(object):
fairy._pool = pool
fairy._counter = 0
fairy._echo = pool._should_log_debug()
if threadconns is not None:
threadconns.current = weakref.ref(fairy)
@@ -684,11 +686,11 @@ class _ConnectionFairy(object):
_close = _checkin
def _reset(self, pool, echo):
def _reset(self, pool):
if pool.dispatch.reset:
pool.dispatch.reset(self, self._connection_record)
if pool._reset_on_return is reset_rollback:
if echo:
if self._echo:
pool.logger.debug("Connection %s rollback-on-return%s",
self.connection,
", via agent"
@@ -698,7 +700,7 @@ class _ConnectionFairy(object):
else:
pool._dialect.do_rollback(self)
elif pool._reset_on_return is reset_commit:
if echo:
if self._echo:
pool.logger.debug("Connection %s commit-on-return%s",
self.connection,
", via agent"
test/engine/test_execute.py
-1
View File
@@ -21,7 +21,6 @@ from sqlalchemy.testing import fixtures
from sqlalchemy.testing.mock import Mock, call, patch
from contextlib import contextmanager
from sqlalchemy.util import nested
import logging.handlers # needed for logging tests to work correctly
users, metadata, users_autoinc = None, None, None
test/engine/test_logging.py
+96 -26
View File
@@ -1,35 +1,23 @@
from sqlalchemy.testing import eq_, assert_raises, assert_raises_message, \
config, is_
import re
from sqlalchemy.testing.util import picklers
from sqlalchemy.interfaces import ConnectionProxy
from sqlalchemy import MetaData, Integer, String, INT, VARCHAR, func, \
bindparam, select, event, TypeDecorator, create_engine, Sequence
from sqlalchemy.sql import column, literal
from sqlalchemy.testing.schema import Table, Column
from sqlalchemy.testing import eq_, assert_raises_message
from sqlalchemy import select
import sqlalchemy as tsa
from sqlalchemy import testing
from sqlalchemy.testing import engines
from sqlalchemy import util
from sqlalchemy.testing.engines import testing_engine
import logging.handlers
from sqlalchemy.dialects.oracle.zxjdbc import ReturningParam
from sqlalchemy.engine import result as _result, default
from sqlalchemy.engine.base import Engine
from sqlalchemy.testing import fixtures
from sqlalchemy.testing.mock import Mock, call, patch
from sqlalchemy.testing import mock
from sqlalchemy.testing.util import lazy_gc
class LogParamsTest(fixtures.TestBase):
__only_on__ = 'sqlite'
__requires__ = 'ad_hoc_engines',
def setup(self):
self.eng = engines.testing_engine(options={'echo':True})
self.eng = engines.testing_engine(options={'echo': True})
self.eng.execute("create table foo (data string)")
self.buf = logging.handlers.BufferingHandler(100)
for log in [
logging.getLogger('sqlalchemy.engine'),
logging.getLogger('sqlalchemy.pool')
]:
log.addHandler(self.buf)
@@ -37,14 +25,13 @@ class LogParamsTest(fixtures.TestBase):
self.eng.execute("drop table foo")
for log in [
logging.getLogger('sqlalchemy.engine'),
logging.getLogger('sqlalchemy.pool')
]:
log.removeHandler(self.buf)
def test_log_large_dict(self):
self.eng.execute(
"INSERT INTO foo (data) values (:data)",
[{"data":str(i)} for i in range(100)]
[{"data": str(i)} for i in range(100)]
)
eq_(
self.buf.buffer[1].message,
@@ -76,7 +63,7 @@ class LogParamsTest(fixtures.TestBase):
"100 total bound parameter sets ... {'data': '98'}, {'data': '99'}\]",
lambda: self.eng.execute(
"INSERT INTO nonexistent (data) values (:data)",
[{"data":str(i)} for i in range(100)]
[{"data": str(i)} for i in range(100)]
)
)
@@ -94,6 +81,88 @@ class LogParamsTest(fixtures.TestBase):
)
)
class PoolLoggingTest(fixtures.TestBase):
def setup(self):
self.existing_level = logging.getLogger("sqlalchemy.pool").level
self.buf = logging.handlers.BufferingHandler(100)
for log in [
logging.getLogger('sqlalchemy.pool')
]:
log.addHandler(self.buf)
def teardown(self):
for log in [
logging.getLogger('sqlalchemy.pool')
]:
log.removeHandler(self.buf)
logging.getLogger("sqlalchemy.pool").setLevel(self.existing_level)
def _queuepool_echo_fixture(self):
return tsa.pool.QueuePool(creator=mock.Mock(), echo='debug')
def _queuepool_logging_fixture(self):
logging.getLogger("sqlalchemy.pool").setLevel(logging.DEBUG)
return tsa.pool.QueuePool(creator=mock.Mock())
def _stpool_echo_fixture(self):
return tsa.pool.SingletonThreadPool(creator=mock.Mock(), echo='debug')
def _stpool_logging_fixture(self):
logging.getLogger("sqlalchemy.pool").setLevel(logging.DEBUG)
return tsa.pool.SingletonThreadPool(creator=mock.Mock())
def _test_queuepool(self, q, dispose=True):
conn = q.connect()
conn.close()
conn = None
conn = q.connect()
conn.close()
conn = None
conn = q.connect()
conn = None
del conn
lazy_gc()
q.dispose()
eq_(
[buf.msg for buf in self.buf.buffer],
[
'Created new connection %r',
'Connection %r checked out from pool',
'Connection %r being returned to pool',
'Connection %s rollback-on-return%s',
'Connection %r checked out from pool',
'Connection %r being returned to pool',
'Connection %s rollback-on-return%s',
'Connection %r checked out from pool',
'Connection %r being returned to pool',
'Connection %s rollback-on-return%s',
'Closing connection %r',
] + (['Pool disposed. %s'] if dispose else [])
)
def test_stpool_echo(self):
q = self._stpool_echo_fixture()
self._test_queuepool(q, False)
def test_stpool_logging(self):
q = self._stpool_logging_fixture()
self._test_queuepool(q, False)
def test_queuepool_echo(self):
q = self._queuepool_echo_fixture()
self._test_queuepool(q)
def test_queuepool_logging(self):
q = self._queuepool_logging_fixture()
self._test_queuepool(q)
class LoggingNameTest(fixtures.TestBase):
__requires__ = 'ad_hoc_engines',
@@ -104,7 +173,7 @@ class LoggingNameTest(fixtures.TestBase):
assert name in (
'sqlalchemy.engine.base.Engine.%s' % eng_name,
'sqlalchemy.pool.%s.%s' %
(eng.pool.__class__.__name__, pool_name)
(eng.pool.__class__.__name__, pool_name)
)
def _assert_no_name_in_execute(self, eng):
@@ -118,15 +187,15 @@ class LoggingNameTest(fixtures.TestBase):
def _named_engine(self, **kw):
options = {
'logging_name':'myenginename',
'pool_logging_name':'mypoolname',
'echo':True
'logging_name': 'myenginename',
'pool_logging_name': 'mypoolname',
'echo': True
}
options.update(kw)
return engines.testing_engine(options=options)
def _unnamed_engine(self, **kw):
kw.update({'echo':True})
kw.update({'echo': True})
return engines.testing_engine(options=kw)
def setup(self):
@@ -183,6 +252,7 @@ class LoggingNameTest(fixtures.TestBase):
eng = self._unnamed_engine(echo='debug', echo_pool='debug')
self._assert_no_name_in_execute(eng)
class EchoTest(fixtures.TestBase):
__requires__ = 'ad_hoc_engines',