summaryrefslogtreecommitdiff
path: root/test/engine/test_logging.py
Commit message (Collapse)AuthorAgeFilesLines
* Replace reset_agent with direct call from connectionMike Bayer2021-03-061-6/+6
| | | | | | | | | | | | | Fixed a regression where the "reset agent" of the connection pool wasn't really being utilized by the :class:`_engine.Connection` when it were closed, and also leading to a double-rollback scenario that was somewhat wasteful. The newer architecture of the engine has been updated so that the connection pool "reset-on-return" logic will be skipped when the :class:`_engine.Connection` explicitly closes out the transaction before returning the pool to the connection. Fixes: #6004 Change-Id: I5d2ac16cac71aa45a00b4b7481d7268bd828a168
* Clarify COMMIT/ROLLBACK logging when autocommit is turned onMike Bayer2021-03-051-0/+85
| | | | | | | | | | | Improved engine logging to note ROLLBACK and COMMIT which is logged while the DBAPI driver is in AUTOCOMMIT mode. These ROLLBACK/COMMIT are library level and do not have any effect when AUTOCOMMIT is in effect, however it's still worthwhile to log as these indicate where SQLAlchemy sees the "transaction" demarcation. Fixes: #6002 Change-Id: I723636515193e0addc86dd0a3132bc23deadb81b
* Implement per-connection logging tokenMike Bayer2021-02-031-0/+71
| | | | | | | | | | | | | | | Added new execution option :paramref:`_engine.Connection.execution_options.logging_token`. This option will add an additional per-message token to log messages generated by the :class:`_engine.Connection` as it executes statements. This token is not part of the logger name itself (that part can be affected using the existing :paramref:`_sa.create_engine.logging_name` parameter), so is appropriate for ad-hoc connection use without the side effect of creating many new loggers. The option can be set at the level of :class:`_engine.Connection` or :class:`_engine.Engine`. Fixes: #5911 Change-Id: Iec9c39b868b3578fcedc1c094dace5b6f64bacea
* reinvent xdist hooks in terms of pytest fixturesMike Bayer2021-01-131-8/+8
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | 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
* correct for "autocommit" deprecation warningMike Bayer2020-12-111-21/+35
| | | | | | | | | | | | Ensure no autocommit warnings occur internally or within tests. Also includes fixes for SQL Server full text tests which apparently have not been working at all for a long time, as it used long removed APIs. CI has not had fulltext running for some years and is now installed. Change-Id: Id806e1856c9da9f0a9eac88cebc7a94ecc95eb96
* Enable pypy tests on github workflowFederico Caselli2020-10-021-0/+3
| | | | | Fixes: #5223 Change-Id: I0952e54ed9af2952ea340be1945311376ffc1ad2
* Update select usage to use the new 1.4 formatFederico Caselli2020-09-081-12/+12
| | | | | | | | | | | | | | | | This change includes mainly that the bracketed use within select() is moved to positional, and keyword arguments are removed from calls to the select() function. it does not yet fully address other issues such as keyword arguments passed to the table.select(). Additionally, allows False / None to both be considered as "disable" for all of select.correlate(), select.correlate_except(), query.correlate(), which establishes consistency with passing of ``False`` for the legact select(correlate=False) argument. Change-Id: Ie6c6e6abfbd3d75d4c8de504c0cf0159e6999108
* Implement rudimentary asyncio support w/ asyncpgMike Bayer2020-08-131-2/+2
| | | | | | | | | | | | | | | | | | | | | | | | | | Using the approach introduced at https://gist.github.com/zzzeek/6287e28054d3baddc07fa21a7227904e We can now create asyncio endpoints that are then handled in "implicit IO" form within the majority of the Core internals. Then coroutines are re-exposed at the point at which we call into asyncpg methods. Patch includes: * asyncpg dialect * asyncio package * engine, result, ORM session classes * new test fixtures, tests * some work with pep-484 and a short plugin for the pyannotate package, which seems to have so-so results Change-Id: Idbcc0eff72c4cad572914acdd6f40ddb1aef1a7d Fixes: #3414
* Turn on caching everywhere, add loggingMike Bayer2020-06-101-9/+14
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | A variety of caching issues found by running all tests with statement caching turned on. The cache system now has a more conservative approach where any subclass of a SQL element will by default invalidate the cache key unless it adds the flag inherit_cache=True at the class level, or if it implements its own caching. Add working caching to a few elements that were omitted previously; fix some caching implementations to suit lesser used edge cases such as json casts and array slices. Refine the way BaseCursorResult and CursorMetaData interact with caching; to suit cases like Alembic modifying table structures, don't cache the cursor metadata if it were created against a cursor.description using non-positional matching, e.g. "select *". if a table re-ordered its columns or added/removed, now that data is obsolete. Additionally we have to adapt the cursor metadata _keymap regardless of if we just processed cursor.description, because if we ran against a cached SQLCompiler we won't have the right columns in _keymap. Other refinements to how and when we do this adaption as some weird cases were exposed in the Postgresql dialect, a text() construct that names just one column that is not actually in the statement. Fixed that also as it looks like a cut-and-paste artifact that doesn't actually affect anything. Various issues with re-use of compiled result maps and cursor metadata in conjunction with tables being changed, such as change in order of columns. mappers can be cleared but the class remains, meaning a mapper has to use itself as the cache key not the class. lots of bound parameter / literal issues, due to Alembic creating a straight subclass of bindparam that renders inline directly. While we can update Alembic to not do this, we have to assume other people might be doing this, so bindparam() implements the inherit_cache=True logic as well that was a bit involved. turn on cache stats in logging. Includes a fix to subqueryloader which moves all setup to the create_row_processor() phase and elminates any storage within the compiled context. This includes some changes to create_row_processor() signature and a revising of the technique used to determine if the loader can participate in polymorphic queries, which is also applied to selectinloading. DML update.values() and ordered_values() now coerces the keys as we have tests that pass an arbitrary class here which only includes __clause_element__(), so the key can't be cached unless it is coerced. this in turn changed how composite attributes support bulk update to use the standard approach of ClauseElement with annotations that are parsed in the ORM context. memory profiling successfully caught that the Session from Query was getting passed into _statement_20() so that was a big win for that test suite. Apparently Compiler had .execute() and .scalar() methods stuck on it, these date back to version 0.4 and there was a single test in the PostgreSQL dialect tests that exercised it for no apparent reason. Removed these methods as well as the concept of a Compiler holding onto a "bind". Fixes: #5386 Change-Id: I990b43aab96b42665af1b2187ad6020bee778784
* Create initial 2.0 engine implementationMike Bayer2020-04-161-2/+2
| | | | | | | | | | | | | | | | | | | Implemented the SQLAlchemy 2 :func:`.future.create_engine` function which is used for forwards compatibility with SQLAlchemy 2. This engine features always-transactional behavior with autobegin. Allow execution options per statement execution. This includes that the before_execute() and after_execute() events now accept an additional dictionary with these options, empty if not passed; a legacy event decorator is added for backwards compatibility which now also emits a deprecation warning. Add some basic tests for execution, transactions, and the new result object. Build out on a new testing fixture that swaps in the future engine completely to start with. Change-Id: I70e7338bb3f0ce22d2f702537d94bb249bd9fb0a Fixes: #4644
* Deprecate plain string in execute and introduce `exec_driver_sql`Federico Caselli2020-03-211-15/+29
| | | | | | | | | | | | | | | Execution of literal sql string is deprecated in the :meth:`.Connection.execute` and a warning is raised when used stating that it will be coerced to :func:`.text` in a future release. To execute a raw sql string the new connection method :meth:`.Connection.exec_driver_sql` was added, that will retain the previous behavior, passing the string to the DBAPI driver unchanged. Usage of scalar or tuple positional parameters in :meth:`.Connection.execute` is also deprecated. Fixes: #4848 Fixes: #5178 Change-Id: I2830181054327996d594f7f0d59c157d477c3aa9
* Fix tests failing for SQLite file databases; repair provisioningGord Thompson2020-03-131-3/+5
| | | | | | | | | | | | | | | | | | | | | | 1. ensure provision.py loads dialect implementations when running reap_dbs.py. Reapers haven't been working since 598f2f7e557073f29563d4d567f43931fc03013f . 2. add some exclusion rules to allow the sqlite_file target to work; add to tox. 3. add reap dbs target for SQLite, repair SQLite drop_db routine which also wasn't doing the right thing for memory databases etc. 4. Fix logging in provision files, as the main provision logger is the one that's enabled by reap_dbs and maybe others, have all the provision files use the provision logger. Fixes: #5180 Fixes: #5168 Change-Id: Ibc1b0106394d20f5bcf847f37b09d185f26ac9b5
* pass executemany context to _repr_paramsMike Bayer2019-10-111-2/+132
| | | | | | | | | | | | | | | | | | Fixed bug where parameter repr as used in logging and error reporting needs additional context in order to distinguish between a list of parameters for a single statement and a list of parameter lists, as the "list of lists" structure could also indicate a single parameter list where the first parameter itself is a list, such as for an array parameter. The engine/connection now passes in an additional boolean indicating how the parameters should be considered. The only SQLAlchemy backend that expects arrays as parameters is that of psycopg2 which uses pyformat parameters, so this issue has not been too apparent, however as other drivers that use positional gain more features it is important that this be supported. It also eliminates the need for the parameter repr function to guess based on the parameter structure passed. Fixes: #4902 Change-Id: I086246ee0eb51484adbefd83e07295fa56576c5f
* Add hide_parameters flag to create_engineMike Bayer2019-08-221-0/+62
| | | | | | | | | Added new parameter :paramref:`.create_engine.hide_parameters` which when set to True will cause SQL parameters to no longer be logged, nor rendered in the string representation of a :class:`.StatementError` object. Fixes: #4815 Change-Id: Ib87f868b6936cf6b42b192644e9d732ec24266c2
* Include newlines in StatementError formattingNate Clark2019-02-201-5/+5
| | | | | | | | | | | | | | | | Revised the formatting for :class:`.StatementError` when stringified. Each error detail is broken up over multiple newlines instead of spaced out on a single line. Additionally, the SQL representation now stringifies the SQL statement rather than using ``repr()``, so that newlines are rendered as is. Pull request courtesy Nate Clark. Fixes: #4500 Closes: #4501 Pull-request: https://github.com/sqlalchemy/sqlalchemy/pull/4501 Pull-request-sha: 60cc0ee68dc96b8f483a60d37bcb26b6c6d53efe Change-Id: I79d8418b7495e5691c9a56f41e79495c26a967ff
* Post black reformattingMike Bayer2019-01-061-4/+7
| | | | | | | | | | | | | Applied on top of a pure run of black -l 79 in I7eda77fed3d8e73df84b3651fd6cfcfe858d4dc9, this set of changes resolves all remaining flake8 conditions for those codes we have enabled in setup.cfg. Included are resolutions for all remaining flake8 issues including shadowed builtins, long lines, import order, unused imports, duplicate imports, and docstring issues. Change-Id: I4f72d3ba1380dd601610ff80b8fb06a2aff8b0fe
* Run black -l 79 against all source filesMike Bayer2019-01-061-111/+89
| | | | | | | | | | | | | | This is a straight reformat run using black as is, with no edits applied at all. The black run will format code consistently, however in some cases that are prevalent in SQLAlchemy code it produces too-long lines. The too-long lines will be resolved in the following commit that will resolve all remaining flake8 issues including shadowed builtins, long lines, import order, unused imports, duplicate imports, and docstring issues. Change-Id: I7eda77fed3d8e73df84b3651fd6cfcfe858d4dc9
* Refactor pool.py into a packageMike Bayer2018-07-091-2/+2
| | | | | | | | | | | for better separation of concerns split out the core pooling constructs from the implementations. also makes more room for new pool classes should we decide to add them. The DBProxy feature is never used so remove it from documentation and split it out. Change-Id: I04c9d7ae1882b17f3cf5c37ed05b781b05ef88fa Fixes: #4255
* Make all tests to be PEP8 compliantKhairi Hafsham2017-02-071-3/+4
| | | | | | | | tested using pycodestyle version 2.2.0 Fixes: #3885 Change-Id: I5df43adc3aefe318f9eeab72a078247a548ec566 Pull-request: https://github.com/zzzeek/sqlalchemy/pull/343
* Support python3.6Mike Bayer2017-01-131-10/+10
| | | | | | | | | | | Corrects some warnings and adds tox config. Adds DeprecationWarning to the error category. Large sweep for string literals w/ backslashes as this is common in docstrings Co-authored-by: Andrii Soldatenko Fixes: #3886 Change-Id: Ia7c838dfbbe70b262622ed0803d581edc736e085 Pull-request: https://github.com/zzzeek/sqlalchemy/pull/337
* - handle parameter sets that aren't correctly formed, so thatMike Bayer2016-02-171-1/+27
| | | | | for example an exception object made within a test suite can still repr (error seen in Keystone)
* - do the trailing comma logic of tuple repr() exactlyMike Bayer2016-02-171-0/+18
|
* - All string formatting of bound parameter sets and result rows forMike Bayer2016-02-171-1/+85
| | | | | | | | | logging, exception, and ``repr()`` purposes now truncate very large scalar values within each collection, including an "N characters truncated" notation, similar to how the display for large multiple-parameter sets are themselves truncated. fixes #2837
* - Exception messages have been spiffed up a bit. The SQL statementMike Bayer2014-10-171-3/+5
| | | | | | | | | | | and parameters are not displayed if None, reducing confusion for error messages that weren't related to a statement. The full module and classname for the DBAPI-level exception is displayed, making it clear that this is a wrapped DBAPI exception. The statement and parameters themselves are bounded within a bracketed sections to better isolate them from the error message and from each other. fixes #3172
* - Fixed bug in connection pool logging where the "connection checked out"Mike Bayer2014-08-201-2/+83
| | | | | | | | 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. fixes #3168
* - pep8 cleanupMike Bayer2014-08-201-24/+13
|
* - ensure all tests are named test_*Mike Bayer2014-07-301-3/+3
|
* - rename __multiple__ to __backend__, and apply __backend__ to a large ↵Mike Bayer2014-03-241-0/+255
number of tests. - move out logging tests from test_execute to test_logging