mirror of
https://github.com/sqlalchemy/sqlalchemy.git
synced 2026-05-17 22:22:13 -04:00
f1e96cb087
To allow the "connection" pytest fixture and others work correctly in conjunction with setup/teardown that expects to be external to the transaction, remove and prevent any usage of "xdist" style names that are hardcoded by pytest to run inside of fixtures, even function level ones. Instead use pytest autouse fixtures to implement our own r"setup|teardown_test(?:_class)?" methods so that we can ensure function-scoped fixtures are run within them. A new more explicit flow is set up within plugin_base and pytestplugin such that the order of setup/teardown steps, which there are now many, is fully documented and controllable. New granularity has been added to the test teardown phase to distinguish between "end of the test" when lock-holding structures on connections should be released to allow for table drops, vs. "end of the test plus its teardown steps" when we can perform final cleanup on connections and run assertions that everything is closed out. From there we can remove most of the defensive "tear down everything" logic inside of engines which for many years would frequently dispose of pools over and over again, creating for a broken and expensive connection flow. A quick test shows that running test/sql/ against a single Postgresql engine with the new approach uses 75% fewer new connections, creating 42 new connections total, vs. 164 new connections total with the previous system. As part of this, the new fixtures metadata/connection/future_connection have been integrated such that they can be combined together effectively. The fixture_session(), provide_metadata() fixtures have been improved, including that fixture_session() now strongly references sessions which are explicitly torn down before table drops occur afer a test. Major changes have been made to the ConnectionKiller such that it now features different "scopes" for testing engines and will limit its cleanup to those testing engines corresponding to end of test, end of test class, or end of test session. The system by which it tracks DBAPI connections has been reworked, is ultimately somewhat similar to how it worked before but is organized more clearly along with the proxy-tracking logic. A "testing_engine" fixture is also added that works as a pytest fixture rather than a standalone function. The connection cleanup logic should now be very robust, as we now can use the same global connection pools for the whole suite without ever disposing them, while also running a query for PostgreSQL locks remaining after every test and assert there are no open transactions leaking between tests at all. Additional steps are added that also accommodate for asyncio connections not explicitly closed, as is the case for legacy sync-style tests as well as the async tests themselves. As always, hundreds of tests are further refined to use the new fixtures where problems with loose connections were identified, largely as a result of the new PostgreSQL assertions, many more tests have moved from legacy patterns into the newest. An unfortunate discovery during the creation of this system is that autouse fixtures (as well as if they are set up by @pytest.mark.usefixtures) are not usable at our current scale with pytest 4.6.11 running under Python 2. It's unclear if this is due to the older version of pytest or how it implements itself for Python 2, as well as if the issue is CPU slowness or just large memory use, but collecting the full span of tests takes over a minute for a single process when any autouse fixtures are in place and on CI the jobs just time out after ten minutes. So at the moment this patch also reinvents a small version of "autouse" fixtures when py2k is running, which skips generating the real fixture and instead uses two global pytest fixtures (which don't seem to impact performance) to invoke the "autouse" fixtures ourselves outside of pytest. This will limit our ability to do more with fixtures until we can remove py2k support. py.test is still observed to be much slower in collection in the 4.6.11 version compared to modern 6.2 versions, so add support for new TOX_POSTGRESQL_PY2K and TOX_MYSQL_PY2K environment variables that will run the suite for fewer backends under Python 2. For Python 3 pin pytest to modern 6.2 versions where performance for collection has been improved greatly. Includes the following improvements: Fixed bug in asyncio connection pool where ``asyncio.TimeoutError`` would be raised rather than :class:`.exc.TimeoutError`. Also repaired the :paramref:`_sa.create_engine.pool_timeout` parameter set to zero when using the async engine, which previously would ignore the timeout and block rather than timing out immediately as is the behavior with regular :class:`.QueuePool`. For asyncio the connection pool will now also not interact at all with an asyncio connection whose ConnectionFairy is being garbage collected; a warning that the connection was not properly closed is emitted and the connection is discarded. Within the test suite the ConnectionKiller is now maintaining strong references to all DBAPI connections and ensuring they are released when tests end, including those whose ConnectionFairy proxies are GCed. Identified cx_Oracle.stmtcachesize as a major factor in Oracle test scalability issues, this can be reset on a per-test basis rather than setting it to zero across the board. the addition of this flag has resolved the long-standing oracle "two task" error problem. For SQL Server, changed the temp table style used by the "suite" tests to be the double-pound-sign, i.e. global, variety, which is much easier to test generically. There are already reflection tests that are more finely tuned to both styles of temp table within the mssql test suite. Additionally, added an extra step to the "dropfirst" mechanism for SQL Server that will remove all foreign key constraints first as some issues were observed when using this flag when multiple schemas had not been torn down. Identified and fixed two subtle failure modes in the engine, when commit/rollback fails in a begin() context manager, the connection is explicitly closed, and when "initialize()" fails on the first new connection of a dialect, the transactional state on that connection is still rolled back. Fixes: #5826 Fixes: #5827 Change-Id: Ib1d05cb8c7cf84f9a4bfd23df397dc23c9329bfe
668 lines
23 KiB
Python
668 lines
23 KiB
Python
import logging.handlers
|
|
|
|
import sqlalchemy as tsa
|
|
from sqlalchemy import bindparam
|
|
from sqlalchemy import Column
|
|
from sqlalchemy import MetaData
|
|
from sqlalchemy import or_
|
|
from sqlalchemy import select
|
|
from sqlalchemy import String
|
|
from sqlalchemy import Table
|
|
from sqlalchemy import testing
|
|
from sqlalchemy import util
|
|
from sqlalchemy.sql import util as sql_util
|
|
from sqlalchemy.testing import assert_raises
|
|
from sqlalchemy.testing import assert_raises_message
|
|
from sqlalchemy.testing import engines
|
|
from sqlalchemy.testing import eq_
|
|
from sqlalchemy.testing import eq_regex
|
|
from sqlalchemy.testing import fixtures
|
|
from sqlalchemy.testing import mock
|
|
from sqlalchemy.testing.util import lazy_gc
|
|
|
|
|
|
def exec_sql(engine, sql, *args, **kwargs):
|
|
with engine.begin() as conn:
|
|
return conn.exec_driver_sql(sql, *args, **kwargs)
|
|
|
|
|
|
class LogParamsTest(fixtures.TestBase):
|
|
__only_on__ = "sqlite"
|
|
__requires__ = ("ad_hoc_engines",)
|
|
|
|
def setup_test(self):
|
|
self.eng = engines.testing_engine(options={"echo": True})
|
|
self.no_param_engine = engines.testing_engine(
|
|
options={"echo": True, "hide_parameters": True}
|
|
)
|
|
exec_sql(self.eng, "create table if not exists foo (data string)")
|
|
exec_sql(
|
|
self.no_param_engine,
|
|
"create table if not exists foo (data string)",
|
|
)
|
|
self.buf = logging.handlers.BufferingHandler(100)
|
|
for log in [logging.getLogger("sqlalchemy.engine")]:
|
|
log.addHandler(self.buf)
|
|
|
|
def teardown_test(self):
|
|
exec_sql(self.eng, "drop table if exists foo")
|
|
for log in [logging.getLogger("sqlalchemy.engine")]:
|
|
log.removeHandler(self.buf)
|
|
|
|
def test_log_large_list_of_dict(self):
|
|
exec_sql(
|
|
self.eng,
|
|
"INSERT INTO foo (data) values (:data)",
|
|
[{"data": str(i)} for i in range(100)],
|
|
)
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] [{'data': '0'}, {'data': '1'}, {'data': '2'}, "
|
|
"{'data': '3'}, "
|
|
"{'data': '4'}, {'data': '5'}, {'data': '6'}, {'data': '7'}"
|
|
" ... displaying 10 of 100 total bound "
|
|
"parameter sets ... {'data': '98'}, {'data': '99'}]",
|
|
)
|
|
|
|
def test_repr_params_large_list_of_dict(self):
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[{"data": str(i)} for i in range(100)],
|
|
batches=10,
|
|
ismulti=True,
|
|
)
|
|
),
|
|
"[{'data': '0'}, {'data': '1'}, {'data': '2'}, {'data': '3'}, "
|
|
"{'data': '4'}, {'data': '5'}, {'data': '6'}, {'data': '7'}"
|
|
" ... displaying 10 of 100 total bound "
|
|
"parameter sets ... {'data': '98'}, {'data': '99'}]",
|
|
)
|
|
|
|
def test_log_no_parameters(self):
|
|
exec_sql(
|
|
self.no_param_engine,
|
|
"INSERT INTO foo (data) values (:data)",
|
|
[{"data": str(i)} for i in range(100)],
|
|
)
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] [SQL parameters hidden due to hide_parameters=True]",
|
|
)
|
|
|
|
def test_log_large_list_of_tuple(self):
|
|
exec_sql(
|
|
self.eng,
|
|
"INSERT INTO foo (data) values (?)",
|
|
[(str(i),) for i in range(100)],
|
|
)
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] [('0',), ('1',), ('2',), ('3',), ('4',), ('5',), "
|
|
"('6',), ('7',) ... displaying 10 of 100 total "
|
|
"bound parameter sets ... ('98',), ('99',)]",
|
|
)
|
|
|
|
def test_log_positional_array(self):
|
|
with self.eng.connect() as conn:
|
|
exc_info = assert_raises(
|
|
tsa.exc.DBAPIError,
|
|
conn.execute,
|
|
tsa.text("SELECT * FROM foo WHERE id IN :foo AND bar=:bar"),
|
|
{"foo": [1, 2, 3], "bar": "hi"},
|
|
)
|
|
|
|
assert (
|
|
"[SQL: SELECT * FROM foo WHERE id IN ? AND bar=?]\n"
|
|
"[parameters: ([1, 2, 3], 'hi')]\n" in str(exc_info)
|
|
)
|
|
|
|
eq_regex(
|
|
self.buf.buffer[1].message,
|
|
r"\[generated .*\] \(\[1, 2, 3\], 'hi'\)",
|
|
)
|
|
|
|
def test_repr_params_positional_array(self):
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[[1, 2, 3], 5], batches=10, ismulti=False
|
|
)
|
|
),
|
|
"[[1, 2, 3], 5]",
|
|
)
|
|
|
|
def test_repr_params_unknown_list(self):
|
|
# not known if given multiparams or not. repr params with
|
|
# straight truncation
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[[i for i in range(300)], 5], batches=10, max_chars=80
|
|
)
|
|
),
|
|
"[[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, ... "
|
|
"(1315 characters truncated) ... , 293, 294, 295, 296, "
|
|
"297, 298, 299], 5]",
|
|
)
|
|
|
|
def test_repr_params_positional_list(self):
|
|
# given non-multi-params in a list. repr params with
|
|
# per-element truncation, mostly does the exact same thing
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[[i for i in range(300)], 5],
|
|
batches=10,
|
|
max_chars=80,
|
|
ismulti=False,
|
|
)
|
|
),
|
|
"[[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 1 ... "
|
|
"(1310 characters truncated) ... "
|
|
"292, 293, 294, 295, 296, 297, 298, 299], 5]",
|
|
)
|
|
|
|
def test_repr_params_named_dict(self):
|
|
# given non-multi-params in a list. repr params with
|
|
# per-element truncation, mostly does the exact same thing
|
|
params = {"key_%s" % i: i for i in range(10)}
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
params, batches=10, max_chars=80, ismulti=False
|
|
)
|
|
),
|
|
repr(params),
|
|
)
|
|
|
|
def test_repr_params_ismulti_named_dict(self):
|
|
# given non-multi-params in a list. repr params with
|
|
# per-element truncation, mostly does the exact same thing
|
|
param = {"key_%s" % i: i for i in range(10)}
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[param for j in range(50)],
|
|
batches=5,
|
|
max_chars=80,
|
|
ismulti=True,
|
|
)
|
|
),
|
|
"[%(param)r, %(param)r, %(param)r ... "
|
|
"displaying 5 of 50 total bound parameter sets ... "
|
|
"%(param)r, %(param)r]" % {"param": param},
|
|
)
|
|
|
|
def test_repr_params_ismulti_list(self):
|
|
# given multi-params in a list. repr params with
|
|
# per-element truncation, mostly does the exact same thing
|
|
eq_(
|
|
repr(
|
|
sql_util._repr_params(
|
|
[
|
|
[[i for i in range(300)], 5],
|
|
[[i for i in range(300)], 5],
|
|
[[i for i in range(300)], 5],
|
|
],
|
|
batches=10,
|
|
max_chars=80,
|
|
ismulti=True,
|
|
)
|
|
),
|
|
"[[[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 1 ... "
|
|
"(1310 characters truncated) ... 292, 293, 294, 295, 296, 297, "
|
|
"298, 299], 5], [[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 1 ... "
|
|
"(1310 characters truncated) ... 292, 293, 294, 295, 296, 297, "
|
|
"298, 299], 5], [[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 1 ... "
|
|
"(1310 characters truncated) ... 292, 293, 294, 295, 296, 297, "
|
|
"298, 299], 5]]",
|
|
)
|
|
|
|
def test_log_large_parameter_single(self):
|
|
import random
|
|
|
|
largeparam = "".join(chr(random.randint(52, 85)) for i in range(5000))
|
|
|
|
exec_sql(self.eng, "INSERT INTO foo (data) values (?)", (largeparam,))
|
|
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] ('%s ... (4702 characters truncated) ... %s',)"
|
|
% (largeparam[0:149], largeparam[-149:]),
|
|
)
|
|
|
|
def test_log_large_multi_parameter(self):
|
|
import random
|
|
|
|
lp1 = "".join(chr(random.randint(52, 85)) for i in range(5))
|
|
lp2 = "".join(chr(random.randint(52, 85)) for i in range(8))
|
|
lp3 = "".join(chr(random.randint(52, 85)) for i in range(670))
|
|
|
|
exec_sql(self.eng, "SELECT ?, ?, ?", (lp1, lp2, lp3))
|
|
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] ('%s', '%s', '%s ... (372 characters truncated) "
|
|
"... %s')" % (lp1, lp2, lp3[0:149], lp3[-149:]),
|
|
)
|
|
|
|
def test_log_large_parameter_multiple(self):
|
|
import random
|
|
|
|
lp1 = "".join(chr(random.randint(52, 85)) for i in range(5000))
|
|
lp2 = "".join(chr(random.randint(52, 85)) for i in range(200))
|
|
lp3 = "".join(chr(random.randint(52, 85)) for i in range(670))
|
|
|
|
exec_sql(
|
|
self.eng,
|
|
"INSERT INTO foo (data) values (?)",
|
|
[(lp1,), (lp2,), (lp3,)],
|
|
)
|
|
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] [('%s ... (4702 characters truncated) ... %s',), "
|
|
"('%s',), "
|
|
"('%s ... (372 characters truncated) ... %s',)]"
|
|
% (lp1[0:149], lp1[-149:], lp2, lp3[0:149], lp3[-149:]),
|
|
)
|
|
|
|
def test_exception_format_dict_param(self):
|
|
exception = tsa.exc.IntegrityError("foo", {"x": "y"}, None)
|
|
eq_regex(
|
|
str(exception),
|
|
r"\(.*.NoneType\) None\n\[SQL: foo\]\n\[parameters: {'x': 'y'}\]",
|
|
)
|
|
|
|
def test_exception_format_hide_parameters(self):
|
|
exception = tsa.exc.IntegrityError(
|
|
"foo", {"x": "y"}, None, hide_parameters=True
|
|
)
|
|
eq_regex(
|
|
str(exception),
|
|
r"\(.*.NoneType\) None\n\[SQL: foo\]\n"
|
|
r"\[SQL parameters hidden due to hide_parameters=True\]",
|
|
)
|
|
|
|
def test_exception_format_hide_parameters_dbapi_round_trip(self):
|
|
assert_raises_message(
|
|
tsa.exc.DBAPIError,
|
|
r".*INSERT INTO nonexistent \(data\) values \(:data\)\]\n"
|
|
r"\[SQL parameters hidden due to hide_parameters=True\]",
|
|
lambda: exec_sql(
|
|
self.no_param_engine,
|
|
"INSERT INTO nonexistent (data) values (:data)",
|
|
[{"data": str(i)} for i in range(10)],
|
|
),
|
|
)
|
|
|
|
def test_exception_format_hide_parameters_nondbapi_round_trip(self):
|
|
foo = Table("foo", MetaData(), Column("data", String))
|
|
|
|
with self.no_param_engine.connect() as conn:
|
|
assert_raises_message(
|
|
tsa.exc.StatementError,
|
|
r"\(sqlalchemy.exc.InvalidRequestError\) A value is required "
|
|
r"for bind parameter 'the_data_2'\n"
|
|
r"\[SQL: SELECT foo.data \nFROM foo \nWHERE "
|
|
r"foo.data = \? OR foo.data = \?\]\n"
|
|
r"\[SQL parameters hidden due to hide_parameters=True\]",
|
|
conn.execute,
|
|
select(foo).where(
|
|
or_(
|
|
foo.c.data == bindparam("the_data_1"),
|
|
foo.c.data == bindparam("the_data_2"),
|
|
)
|
|
),
|
|
{"the_data_1": "some data"},
|
|
)
|
|
|
|
def test_exception_format_unexpected_parameter(self):
|
|
# test that if the parameters aren't any known type, we just
|
|
# run through repr()
|
|
exception = tsa.exc.IntegrityError("foo", "bar", "bat")
|
|
eq_regex(
|
|
str(exception),
|
|
r"\(.*.str\) bat\n\[SQL: foo\]\n\[parameters: 'bar'\]",
|
|
)
|
|
|
|
def test_exception_format_unexpected_member_parameter(self):
|
|
# test that if the parameters aren't any known type, we just
|
|
# run through repr()
|
|
exception = tsa.exc.IntegrityError("foo", ["bar", "bat"], "hoho")
|
|
eq_regex(
|
|
str(exception),
|
|
r"\(.*.str\) hoho\n\[SQL: foo\]\n\[parameters: \['bar', 'bat'\]\]",
|
|
)
|
|
|
|
def test_result_large_param(self):
|
|
import random
|
|
|
|
largeparam = "".join(chr(random.randint(52, 85)) for i in range(5000))
|
|
|
|
self.eng.echo = "debug"
|
|
result = exec_sql(self.eng, "SELECT ?", (largeparam,))
|
|
|
|
row = result.first()
|
|
|
|
eq_(
|
|
self.buf.buffer[2].message,
|
|
"[raw sql] ('%s ... (4702 characters truncated) ... %s',)"
|
|
% (largeparam[0:149], largeparam[-149:]),
|
|
)
|
|
|
|
if util.py3k:
|
|
eq_(
|
|
self.buf.buffer[5].message,
|
|
"Row ('%s ... (4702 characters truncated) ... %s',)"
|
|
% (largeparam[0:149], largeparam[-149:]),
|
|
)
|
|
else:
|
|
eq_(
|
|
self.buf.buffer[5].message,
|
|
"Row (u'%s ... (4703 characters truncated) ... %s',)"
|
|
% (largeparam[0:148], largeparam[-149:]),
|
|
)
|
|
|
|
if util.py3k:
|
|
eq_(
|
|
repr(row),
|
|
"('%s ... (4702 characters truncated) ... %s',)"
|
|
% (largeparam[0:149], largeparam[-149:]),
|
|
)
|
|
else:
|
|
eq_(
|
|
repr(row),
|
|
"(u'%s ... (4703 characters truncated) ... %s',)"
|
|
% (largeparam[0:148], largeparam[-149:]),
|
|
)
|
|
|
|
def test_error_large_dict(self):
|
|
assert_raises_message(
|
|
tsa.exc.DBAPIError,
|
|
r".*INSERT INTO nonexistent \(data\) values \(:data\)\]\n"
|
|
r"\[parameters: "
|
|
r"\[{'data': '0'}, {'data': '1'}, {'data': '2'}, "
|
|
r"{'data': '3'}, {'data': '4'}, {'data': '5'}, "
|
|
r"{'data': '6'}, {'data': '7'} ... displaying 10 of "
|
|
r"100 total bound parameter sets ... {'data': '98'}, "
|
|
r"{'data': '99'}\]",
|
|
lambda: exec_sql(
|
|
self.eng,
|
|
"INSERT INTO nonexistent (data) values (:data)",
|
|
[{"data": str(i)} for i in range(100)],
|
|
),
|
|
)
|
|
|
|
def test_error_large_list(self):
|
|
assert_raises_message(
|
|
tsa.exc.DBAPIError,
|
|
r".*INSERT INTO nonexistent \(data\) values "
|
|
r"\(\?\)\]\n\[parameters: \[\('0',\), \('1',\), \('2',\), "
|
|
r"\('3',\), \('4',\), \('5',\), \('6',\), \('7',\) "
|
|
r"... displaying "
|
|
r"10 of 100 total bound parameter sets ... "
|
|
r"\('98',\), \('99',\)\]",
|
|
lambda: exec_sql(
|
|
self.eng,
|
|
"INSERT INTO nonexistent (data) values (?)",
|
|
[(str(i),) for i in range(100)],
|
|
),
|
|
)
|
|
|
|
|
|
class PoolLoggingTest(fixtures.TestBase):
|
|
def setup_test(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_test(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)
|
|
|
|
@testing.requires.predictable_gc
|
|
def test_queuepool_echo(self):
|
|
q = self._queuepool_echo_fixture()
|
|
self._test_queuepool(q)
|
|
|
|
@testing.requires.predictable_gc
|
|
def test_queuepool_logging(self):
|
|
q = self._queuepool_logging_fixture()
|
|
self._test_queuepool(q)
|
|
|
|
|
|
class LoggingNameTest(fixtures.TestBase):
|
|
__requires__ = ("ad_hoc_engines",)
|
|
|
|
def _assert_names_in_execute(self, eng, eng_name, pool_name):
|
|
with eng.connect() as conn:
|
|
conn.execute(select(1))
|
|
assert self.buf.buffer
|
|
for name in [b.name for b in self.buf.buffer]:
|
|
assert name in (
|
|
"sqlalchemy.engine.Engine.%s" % eng_name,
|
|
"sqlalchemy.pool.impl.%s.%s"
|
|
% (eng.pool.__class__.__name__, pool_name),
|
|
)
|
|
|
|
def _assert_no_name_in_execute(self, eng):
|
|
with eng.connect() as conn:
|
|
conn.execute(select(1))
|
|
assert self.buf.buffer
|
|
for name in [b.name for b in self.buf.buffer]:
|
|
assert name in (
|
|
"sqlalchemy.engine.Engine",
|
|
"sqlalchemy.pool.impl.%s" % eng.pool.__class__.__name__,
|
|
)
|
|
|
|
def _named_engine(self, **kw):
|
|
options = {
|
|
"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})
|
|
return engines.testing_engine(options=kw)
|
|
|
|
def setup_test(self):
|
|
self.buf = logging.handlers.BufferingHandler(100)
|
|
for log in [
|
|
logging.getLogger("sqlalchemy.engine"),
|
|
logging.getLogger("sqlalchemy.pool"),
|
|
]:
|
|
log.addHandler(self.buf)
|
|
|
|
def teardown_test(self):
|
|
for log in [
|
|
logging.getLogger("sqlalchemy.engine"),
|
|
logging.getLogger("sqlalchemy.pool"),
|
|
]:
|
|
log.removeHandler(self.buf)
|
|
|
|
def test_named_logger_names(self):
|
|
eng = self._named_engine()
|
|
eq_(eng.logging_name, "myenginename")
|
|
eq_(eng.pool.logging_name, "mypoolname")
|
|
|
|
def test_named_logger_names_after_dispose(self):
|
|
eng = self._named_engine()
|
|
with eng.connect() as conn:
|
|
conn.execute(select(1))
|
|
eng.dispose()
|
|
eq_(eng.logging_name, "myenginename")
|
|
eq_(eng.pool.logging_name, "mypoolname")
|
|
|
|
def test_unnamed_logger_names(self):
|
|
eng = self._unnamed_engine()
|
|
eq_(eng.logging_name, None)
|
|
eq_(eng.pool.logging_name, None)
|
|
|
|
def test_named_logger_execute(self):
|
|
eng = self._named_engine()
|
|
self._assert_names_in_execute(eng, "myenginename", "mypoolname")
|
|
|
|
def test_named_logger_echoflags_execute(self):
|
|
eng = self._named_engine(echo="debug", echo_pool="debug")
|
|
self._assert_names_in_execute(eng, "myenginename", "mypoolname")
|
|
|
|
def test_named_logger_execute_after_dispose(self):
|
|
eng = self._named_engine()
|
|
with eng.connect() as conn:
|
|
conn.execute(select(1))
|
|
eng.dispose()
|
|
self._assert_names_in_execute(eng, "myenginename", "mypoolname")
|
|
|
|
def test_unnamed_logger_execute(self):
|
|
eng = self._unnamed_engine()
|
|
self._assert_no_name_in_execute(eng)
|
|
|
|
def test_unnamed_logger_echoflags_execute(self):
|
|
eng = self._unnamed_engine(echo="debug", echo_pool="debug")
|
|
self._assert_no_name_in_execute(eng)
|
|
|
|
|
|
class EchoTest(fixtures.TestBase):
|
|
__requires__ = ("ad_hoc_engines",)
|
|
|
|
def setup_test(self):
|
|
self.level = logging.getLogger("sqlalchemy.engine").level
|
|
logging.getLogger("sqlalchemy.engine").setLevel(logging.WARN)
|
|
self.buf = logging.handlers.BufferingHandler(100)
|
|
logging.getLogger("sqlalchemy.engine").addHandler(self.buf)
|
|
|
|
def teardown_test(self):
|
|
logging.getLogger("sqlalchemy.engine").removeHandler(self.buf)
|
|
logging.getLogger("sqlalchemy.engine").setLevel(self.level)
|
|
|
|
def _testing_engine(self):
|
|
e = engines.testing_engine()
|
|
|
|
# do an initial execute to clear out 'first connect'
|
|
# messages
|
|
with e.connect() as conn:
|
|
conn.execute(select(10)).close()
|
|
self.buf.flush()
|
|
|
|
return e
|
|
|
|
def test_levels(self):
|
|
e1 = engines.testing_engine()
|
|
|
|
eq_(e1._should_log_info(), False)
|
|
eq_(e1._should_log_debug(), False)
|
|
eq_(e1.logger.isEnabledFor(logging.INFO), False)
|
|
eq_(e1.logger.getEffectiveLevel(), logging.WARN)
|
|
|
|
e1.echo = True
|
|
eq_(e1._should_log_info(), True)
|
|
eq_(e1._should_log_debug(), False)
|
|
eq_(e1.logger.isEnabledFor(logging.INFO), True)
|
|
eq_(e1.logger.getEffectiveLevel(), logging.INFO)
|
|
|
|
e1.echo = "debug"
|
|
eq_(e1._should_log_info(), True)
|
|
eq_(e1._should_log_debug(), True)
|
|
eq_(e1.logger.isEnabledFor(logging.DEBUG), True)
|
|
eq_(e1.logger.getEffectiveLevel(), logging.DEBUG)
|
|
|
|
e1.echo = False
|
|
eq_(e1._should_log_info(), False)
|
|
eq_(e1._should_log_debug(), False)
|
|
eq_(e1.logger.isEnabledFor(logging.INFO), False)
|
|
eq_(e1.logger.getEffectiveLevel(), logging.WARN)
|
|
|
|
def test_echo_flag_independence(self):
|
|
"""test the echo flag's independence to a specific engine."""
|
|
|
|
e1 = self._testing_engine()
|
|
e2 = self._testing_engine()
|
|
|
|
e1.echo = True
|
|
|
|
with e1.connect() as conn:
|
|
conn.execute(select(1)).close()
|
|
|
|
with e2.connect() as conn:
|
|
conn.execute(select(2)).close()
|
|
|
|
e1.echo = False
|
|
|
|
with e1.connect() as conn:
|
|
conn.execute(select(3)).close()
|
|
with e2.connect() as conn:
|
|
conn.execute(select(4)).close()
|
|
|
|
e2.echo = True
|
|
with e1.connect() as conn:
|
|
conn.execute(select(5)).close()
|
|
with e2.connect() as conn:
|
|
conn.execute(select(6)).close()
|
|
|
|
assert self.buf.buffer[0].getMessage().startswith("SELECT 1")
|
|
assert self.buf.buffer[2].getMessage().startswith("SELECT 6")
|
|
assert len(self.buf.buffer) == 4
|