[Sqlalchemy-tickets] [sqlalchemy] #2864: Disconnect via IDLE_TIME resource limit not handled by SQL
Brought to you by:
zzzeek
|
From: sqlalchemy <mi...@zz...> - 2013-11-14 17:18:32
|
#2864: Disconnect via IDLE_TIME resource limit not handled by SQLAlchemy
----------------------+-----------------------------------------
Reporter: Bluehorn | Owner: zzzeek
Type: defect | Status: new
Priority: medium | Milestone:
Component: oracle | Severity: no triage selected yet
Keywords: | Progress State: awaiting triage
----------------------+-----------------------------------------
tl;dr: Error code ORA-02396 is missing in
`OracleDialect_cx_oracle.is_disconnect`.
We have an application where the Oracle server is configured to
automatically disconnect clients by the IDLE_TIME resource limit. This
leads to the ORA-02396 error code, which is never seen from the
application side.
Example code:
{{{
#!python
import logging
from sqlalchemy import *
from sqlalchemy.exc import DBAPIError
demo_query = "select 42 from dual"
if __name__ == "__main__":
logging.basicConfig(level=logging.INFO)
engine = create_engine("oracle://loco_tl:loco_tl@loco_tl") # XXX:
Adjust database URL
print "Running a query from a fresh engine:"
print "SQL: %r -> %r" % (demo_query,
engine.execute(demo_query).scalar())
print "Status of the connection pool: %s" % engine.pool.status()
print "Press enter after connection was sniped by Oracle."
raw_input()
try:
print "Running the query from the same engine:"
print "SQL: %r -> %r" % (demo_query,
engine.execute(demo_query).scalar())
except DBAPIError, e:
if not e.connection_invalidated:
raise
print "Connection was invalidated, retrying:"
print "SQL: %r -> %r" % (demo_query,
engine.execute(demo_query).scalar())
}}}
Expected output in my case:
{{{
$ python initial.py
Running a query from a fresh engine:
SQL: 'select 42 from dual' -> 42
Status of the connection pool: Pool size: 5 Connections in pool: 1
Current Overflow: -4 Current Checked out connections: 0
Press enter after connection was sniped by Oracle.
Running the query from the same engine:
Connection was invalidated, retrying:
SQL: 'select 42 from dual' -> 42
}}}
Instead I get the following output:
{{{
$ python initial.py
Running a query from a fresh engine:
SQL: 'select 42 from dual' -> 42
Status of the connection pool: Pool size: 5 Connections in pool: 1
Current Overflow: -4 Current Checked out connections: 0
Press enter after connection was sniped by Oracle.
Running the query from the same engine:
ERROR:sqlalchemy.pool.QueuePool:Exception closing connection
<cx_Oracle.Connection to loco_tl@loco_tl>
Traceback (most recent call last):
File "../python2.7/site-packages/sqlalchemy/pool.py", line 191, in
_close_connection
self._dialect.do_close(connection)
File "../python2.7/site-packages/sqlalchemy/engine/default.py", line
352, in do_close
dbapi_connection.close()
OperationalError: ORA-01012: not logged on
Process ID: 25873
Session ID: 25 Serial number: 10916
Traceback (most recent call last):
File "initial.py", line 23, in <module>
print "SQL: %r -> %r" % (demo_query,
engine.execute(demo_query).scalar())
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 1598,
in execute
return connection.execute(statement, *multiparams, **params)
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 656,
in execute
return self._execute_text(object, multiparams, params)
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 805,
in _execute_text
statement, parameters
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 874,
in _execute_context
context)
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 1013,
in _handle_dbapi_exception
self._autorollback()
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 556,
in _autorollback
self._rollback_impl()
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 476,
in _rollback_impl
self._handle_dbapi_exception(e, None, None, None, None)
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 991,
in _handle_dbapi_exception
exc_info
File "../python2.7/site-packages/sqlalchemy/util/compat.py", line 185,
in raise_from_cause
reraise(type(exception), exception, tb=exc_tb)
File "../python2.7/site-packages/sqlalchemy/engine/base.py", line 473,
in _rollback_impl
self.engine.dialect.do_rollback(self.connection)
File "../python2.7/site-packages/sqlalchemy/engine/default.py", line
346, in do_rollback
dbapi_connection.rollback()
sqlalchemy.exc.OperationalError: (OperationalError) ORA-01012: not logged
on
Process ID: 25873
Session ID: 25 Serial number: 10916
None None
}}}
My current solution is to replace the Oracle dialect like this (which
would also make a nice addition to the documentation I think because it
shows how to overwrite specifics of a dialect class):
{{{
#!python
from sqlalchemy.dialects import registry, oracle
class MyOracleDialect(oracle.cx_oracle.OracleDialect_cx_oracle):
def is_disconnect(self, e, connection, cursor):
error, = e.args
if isinstance(e, self.dbapi.InterfaceError):
return "not connected" in str(e)
elif hasattr(error, 'code'):
# logging.info("MyOracleDialect.is_disconnect: ORA-%s",
error.code)
# ORA-00028: your session has been killed
# ORA-03114: not connected to ORACLE
# ORA-03113: end-of-file on communication channel
# ORA-03135: connection lost contact
# ORA-01033: ORACLE initialization or shutdown in progress
# ORA-02396: exceeded maximum idle time, please connect again
# TODO: Others ?
return error.code in (28, 3114, 3113, 3135, 1033, 2396)
else:
return False
registry.register("oracle", __name__, "MyOracleDialect")
}}}
With this addition the actual behaviour still falls a bit short but is
good enough for us:
{{{
$ python fixed.py
Running a query from a fresh engine:
SQL: 'select 42 from dual' -> 42
Status of the connection pool: Pool size: 5 Connections in pool: 1
Current Overflow: -4 Current Checked out connections: 0
Press enter after connection was sniped by Oracle.
Running the query from the same engine:
ERROR:sqlalchemy.pool.QueuePool:Exception closing connection
<cx_Oracle.Connection to loco_tl@loco_tl>
Traceback (most recent call last):
File "../python2.7/site-packages/sqlalchemy/pool.py", line 191, in
_close_connection
self._dialect.do_close(connection)
File "../python2.7/site-packages/sqlalchemy/engine/default.py", line
352, in do_close
dbapi_connection.close()
OperationalError: ORA-01012: not logged on
Process ID: 23387
Session ID: 58 Serial number: 6081
Connection was invalidated, retrying:
SQL: 'select 42 from dual' -> 42
}}}
It is unfortunate that closing the connection fails here as it was in fact
closed (or rather disabled) on the server side. Doesn't really matter for
us as the message does not do any harm other than adding a bit to the log
files.
Tested with the following version of SQLAlchemy:
{{{
#!sh
torsten@sharokan:~/workspace/sqlalchemy$ git describe --tags
rel_0_9_0b1-12-g5d0e844
}}}
--
Ticket URL: <http://www.sqlalchemy.org/trac/ticket/2864>
sqlalchemy <http://www.sqlalchemy.org/>
The Database Toolkit for Python
|