Skip to content

session must close connection if begin fails #5034

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
shinberg opened this issue Dec 13, 2019 · 22 comments
Closed

session must close connection if begin fails #5034

shinberg opened this issue Dec 13, 2019 · 22 comments
Labels
bug Something isn't working orm
Milestone

Comments

@shinberg
Copy link

Hi,

I was constantly experiencing the following exception while using sqlalchemy + sqlite:
SQLite objects created in a thread can only be used in that same thread.

Actually I don't think that I used the SA constructions in some wrong way, I always insured all transactions are either committed/rolled back and closed as well.

And long story short I found the reason (I was frequent reason for me at least ): If the database is locked exception occurs at the following line then the underlying Connection and _ConnectionFairy object is dangled.

This in turn means that when Session.close() is called - the dangling _ConnectionFairy is not released. And finally the noticed _ConnectionFairy object is often released in another thread and causes SQLite objects created in a thread can only be used in that same thread. exception.

What should I do to handle this? I didn't find anything that could help in the SA docs.
Please don't tell me that sqlite is not for concurrency and so on, it's not precisely like that, it is probably not the best DB for concurrency but knowing all proc and cons of this simple DB I should be able to use this.

And also, why didn't you store the connection (which is coded here) before beginning the transaction? It would solve the issue forever.

Thank you.

@shinberg shinberg changed the title _ConnectionFairy deleted in another thread. dangling _ConnectionFairy deleted in another thread(sqlite). Dec 13, 2019
@zzzeek zzzeek added the question issue where a "fix" on the SQLAlchemy side is unlikely, hence more of a usage question label Dec 13, 2019
@shinberg
Copy link
Author

Update: probably this issue occurs only when using the transaction level customization with event listeners:

    @event.listens_for(engine, "begin")
    def do_begin(conn):
        conn.execute("BEGIN EXCLUSIVE")

Which I used in the software.

I guess without usage of this hook there would be no such issues because this hook implicitly disables default exception handling of Connection class here because actual transaction begin statements executed here instead.

That might be the reason of dangling _ConnectionFairy finally.

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

hi there -

I'm not really following what you are experiencing, there is no "disabling of exception handling" implied by the code you illustrated. There is also no "dangling connection fairy" I'm aware of either as the ConnectionFairy is explicitly closed out when the connection is returned to the connection pool. The SQLite connection is detached from the object itself so even if it were floating around somehow, there's nothing attached to it.

At the very least i would need to see a stack trace to illustrate what you are seeing and very likely a full MCVE for a complete understanding. Since what you're doing is in one of our recipes mentioned below I'll do a simple test right now.

My suspicion is that you are following the recipe at https://docs.sqlalchemy.org/en/13/dialects/sqlite.html#serializable-isolation-savepoints-transactional-ddl and perhaps didn't also disable SQLite's isolation level, so perhaps it is trying to BEGIN twice, or something, or perhaps that our recipe simply has an issue with threads such that we may need to add event handlers for commit/rollback as well.

@zzzeek zzzeek added the sqlite label Dec 13, 2019
@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

here's the test script, does not produce any error. Please see if you can modify this to illustrate the failure you are getting. I tried in Python 2.7 and 3.7, no issue.


import sys
import threading
import time

from sqlalchemy import create_engine
from sqlalchemy import event
from sqlalchemy.orm import Session

engine = create_engine("sqlite:///myfile.db", echo_pool="debug")


@event.listens_for(engine, "connect")
def do_connect(dbapi_connection, connection_record):
    # disable pysqlite's emitting of the BEGIN statement entirely.
    # also stops it from emitting COMMIT before any DDL.
    dbapi_connection.isolation_level = None


@event.listens_for(engine, "begin")
def do_begin(conn):
    # emit our own BEGIN
   # UPDATE, tried all three of these, no failures yet
    conn.execute("BEGIN IMMEDIATE")
   #  conn.execute("BEGIN EXCLUSIVE")
   #  conn.execute("BEGIN")

def do_a_thing():
    if sys.version_info < (3,):
        import thread
        t_ident =  thread.get_ident()
    else:
        t_ident = threading.get_ident()
    counter = 0
    while True:
        counter += 1
        s = Session(engine)
        print(s.scalar("SELECT '%s %s'" % (t_ident, counter)))
        s.close()
        time.sleep(0.5)


threads = [threading.Thread(target=do_a_thing) for i in range(10)]
for t in threads:
    t.start()
for t in threads:
    t.join()


@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

also if I remove the isolation level part, it still succeeds. the pool echo illustrates connections being returned properly. Thanks for your continued help!

@shinberg
Copy link
Author

Sorry, Actually I use
BEGIN IMMEDIATE

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

I've tried both:

conn.execute("BEGIN EXCLUSIVE")
 conn.execute("BEGIN IMMEDIATE")

no failure, python 2 or 3. Please share Python version, SQlite version , stacktrace, thanks.

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

I've tried with and without the isolation level setting and with and without emitting any SQL (as SQlite emits BEGIN under certain circumstances only), can't reproduce yet.

@shinberg
Copy link
Author

That can help to reproduce.
Currently I'm trying to get the stack trace.
SQLAlchemy 1.3.1
Python 3.7

sqlite version I don't know since currently running on windows and pip installed some version on its own

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

windows is obviously a huge factor for things like this

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

are you running with any special Python GC flags ?

@shinberg
Copy link
Author

Everything is possible, but actually I don't see the code where exception from BEGIN statement will be handled in this case.
Still trying to get stacktrace...

@shinberg
Copy link
Author

The traceback of exception that causes dangling connection on my env:

  File "\AppData\Local\Programs\Python\Python37\lib\threading.py", line 885, in _bootstrap
    self._bootstrap_inner()
  File "\AppData\Local\Programs\Python\Python37\lib\threading.py", line 917, in _bootstrap_inner
    self.run()
  File "\PycharmProjects\project\client\scheduled\sftp\series.py", line 390, in run
    self._scheduler.run()
  File "\AppData\Local\Programs\Python\Python37\lib\sched.py", line 151, in run
    action(*argument, **kwargs)
  File "\PycharmProjects\project\client\scheduled\sftp\series.py", line 333, in series_check
    series = self._storage.get_ready_series(for_update=True)
  File "\PycharmProjects\project\client\data\storage\request.py", line 650, in get_ready_series
    result = (query.with_for_update() if for_update else query).first()
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3215, in first
    ret = list(self[0:1])
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3007, in __getitem__
    return list(res)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3317, in __iter__
    return self._execute_and_instances(context)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3339, in _execute_and_instances
    querycontext, self._connection_from_session, close_with_result=True
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3354, in _get_bind_args
    mapper=self._bind_mapper(), clause=querycontext.statement, **kw
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\query.py", line 3332, in _connection_from_session
    conn = self.session.connection(**kw)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\session.py", line 1133, in connection
    execution_options=execution_options,
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\session.py", line 1139, in _connection_for_bind
    engine, execution_options
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\orm\session.py", line 445, in _connection_for_bind
    transaction = conn.begin()
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 635, in begin
    self.__transaction = RootTransaction(self)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 1751, in __init__
    self.connection._begin_impl(self)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 720, in _begin_impl
    self.dispatch.begin(self)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\event\attr.py", line 297, in __call__
    fn(*args, **kw)
  File "\PycharmProjects\project\client\data\storage\storage.py", line 75, in do_begin
    conn.execute("BEGIN IMMEDIATE")
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 994, in execute
    return self._execute_text(object_, multiparams, params)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 1167, in _execute_text
    parameters,
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 1260, in _execute_context
    e, statement, parameters, cursor, context
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 1478, in _handle_dbapi_exception
    util.raise_from_cause(sqlalchemy_exception, exc_info)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\util\compat.py", line 383, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\util\compat.py", line 128, in reraise
    raise value.with_traceback(tb)
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\base.py", line 1256, in _execute_context
    cursor, statement, parameters, context
  File "\PycharmProjects\project\venv\lib\site-packages\sqlalchemy\engine\default.py", line 569, in do_execute
    cursor.execute(statement, parameters)

@shinberg
Copy link
Author

shinberg commented Dec 13, 2019

Double checked, isolation level setting is currently looks like the following (seems to be correct):

@sqlalchemy.event.listens_for(sqlalchemy.engine.Engine, "connect")
def do_connect(dbapi_connection, _):
    # disable pysqlite's emitting of the BEGIN statement entirely.
    # also stops it from emitting COMMIT before any DDL.
    dbapi_connection.isolation_level = None

@shinberg
Copy link
Author

Tried your sample on my env - I got no issues too.
So, then I tried to catch any database locks using:

    try:
        conn.execute("BEGIN IMMEDIATE")
    except Exception:
        raise

And set BP on raise, but - no database lock exception raised - that's the reason, need to get DB lock error somehow to reproduce it simply (or probably any other exception could work, but I'm not sure).

@gordthompson
Copy link
Member

Seeing as how this involves Windows and SQLite, there may be some commonality with #4946

@shinberg
Copy link
Author

shinberg commented Dec 13, 2019

Got it, just place sleep in another place:

def do_a_thing():
    if sys.version_info < (3,):
        import thread
        t_ident =  thread.get_ident()
    else:
        t_ident = threading.get_ident()
    counter = 0
    while True:
        counter += 1
        s = Session(engine)
        print(s.scalar("SELECT '%s %s'" % (t_ident, counter)))
        time.sleep(0.5)
        s.close()

placing sleep before close helps to get db lock exception and reproduce the whole issue, finally I'm getting SQLite objects created in a thread can only be used in that same thread. The object was created in thread id 48248 and this is thread id 57504 in my console for this modified version of your sample.

@shinberg
Copy link
Author

are you running with any special Python GC flags ?

no

@shinberg
Copy link
Author

I hope it helped to reproduce.
Currently I just closing connection in case if BEGIN IMMEDIATE raised any exception:

@sqlalchemy.event.listens_for(sqlalchemy.engine.Engine, "begin")
def do_begin(conn):
    try:
        conn.execute("BEGIN IMMEDIATE")
    except Exception:
        conn.close()
        raise

But I just interested whether there are some more elegant way to prevent from this.
If not - probably makes sense to update the event hook/workaround recipe for sqlite.

@zzzeek
Copy link
Member

zzzeek commented Dec 13, 2019

oh. OK, I see that your initial description talked about "database is locked" but you didn't illustrate how you were getting that or where it was happening or why. In the future, I only need a stack trace, no need to try to diagnose the problem, just the stack traces here (edit: and the error message that follows it also), thanks.

fix will be in 1.3.12.

@zzzeek zzzeek changed the title dangling _ConnectionFairy deleted in another thread(sqlite). session must close connection if begin fails Dec 13, 2019
@zzzeek zzzeek added bug Something isn't working orm and removed question issue where a "fix" on the SQLAlchemy side is unlikely, hence more of a usage question sqlite labels Dec 13, 2019
@zzzeek zzzeek added this to the 1.3.xx milestone Dec 13, 2019
@sqla-tester
Copy link
Collaborator

Mike Bayer has proposed a fix for this issue in the master branch:

Close connection if begin fails https://gerrit.sqlalchemy.org/1611

@sqla-tester
Copy link
Collaborator

Mike Bayer has proposed a fix for this issue in the rel_1_3 branch:

Close connection if begin fails https://gerrit.sqlalchemy.org/1612

sqlalchemy-bot pushed a commit that referenced this issue Dec 13, 2019

Verified

This commit was created on GitHub.com and signed with GitHub’s verified signature. The key has expired.
Fixed issue where by if the "begin" of a transaction failed at the Core
engine/connection level, such as due to network error or database is locked
for some transactional recipes, within the context of the :class:`.Session`
procuring that connection from the connection pool and then immediately
returning it, the ORM :class:`.Session` would not close the connection
despite this connection not being stored within the state of that
:class:`.Session`.  This would lead to the connection being cleaned out by
the connection pool weakref handler within garbage collection which is an
unpreferred codepath that in some special configurations can emit errors in
standard error.

Fixes: #5034
Change-Id: I6502a55791d86845f34bc10889c218f00765dfdc
(cherry picked from commit ff47115)
@shinberg
Copy link
Author

oh. OK, I see that your initial description talked about "database is locked" but you didn't illustrate how you were getting that or where it was happening or why. In the future, I only need a stack trace, no need to try to diagnose the problem, just the stack traces here (edit: and the error message that follows it also), thanks.

fix will be in 1.3.12.

ok, I didn't want to create an issue without diagnosis because I was not sure that I use SA properly otherwise.
Thanks for as quick as a lightening fix.

@zzzeek zzzeek modified the milestones: 1.3.xx, 1.3.x Dec 18, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working orm
Projects
None yet
Development

No branches or pull requests

4 participants