We don't know how to use SQLAlchemy sessions

We use sqlalchemy in ckan and often we run into problems with DetachedInstanceErrors. For this reason, we normally jam all the data from a model object into a dictionary to avoid getting the DetachedInstanceError. This isn't sqlachemy's fault, it's more than likely that we are just incapable of using it properly.

For a while, we kept on running into issues where paster db clean would hang and I spent a while trying to figure out what the hell was going on and what was wrong with the session.

As it turned out, there was nothing wrong session really, it was just that we were handling it badly for command line functions. There were basically 2 problems.

1. Not closing transactions that are implicity opened by sqlalchemy
2. Closing and removing a session and then attempting to use the sqlalchemy objects from that session causing DetachedInstanceErrors

To demonstrate this, we're going to use do some fiddling with ckan from the ipython command line shell. We'll start by basically running through ckan's database initialisation code, but we'll pass in echo=True, so that all the SQL statements that are execute are echoed onto the command line.

 In [1]: from sqlalchemy import create_engine, orm  
 In [2]: from ckan import model  
 In [3]: from ckan.logic import get_action  
 In [4]: engine = create_engine('postgresql://ckan_default:pass@localhost/ckan_default', echo=True)  
 In [5]: model.init_model(engine)  
 <...snip...>      
 2014-05-21 12:31:50,892 INFO sqlalchemy.engine.base.Engine {'table_oid': 641922}  
 <...snip...>      

So we're not actually connected to the database yet, sqlalchemy will connect when we issue a query to it.

 In [6]: dataset = model.Session.query(model.Package).all()[0]  
 2014-05-21 12:31:54,778 INFO sqlalchemy.engine.base.Engine BEGIN (implicit)  
 2014-05-21 12:31:54,781 INFO sqlalchemy.engine.base.Engine SELECT package.id AS package_id, package.name AS package_name, package.title AS package_title, package.version AS package_version, package.url AS package_url, package.author AS package_author, package.author_email AS package_author_email, package.maintainer AS package_maintainer, package.maintainer_email AS package_maintainer_email, package.notes AS package_notes, package.license_id AS package_license_id, package.type AS package_type, package.owner_org AS package_owner_org, package.creator_user_id AS package_creator_user_id, package.metadata_modified AS package_metadata_modified, package.private AS package_private, package.state AS package_state, package.revision_id AS package_revision_id   
 FROM package ORDER BY package.name  
 2014-05-21 12:31:54,781 INFO sqlalchemy.engine.base.Engine {}  
 In [7]: dataset  
 Out[7]: <Package id=65a809dc-dd5b-4995-9cb5-1148bc59e385 name=test title=test version= url= author= author_email= maintainer= maintainer_email= notes= license_id=notspecified type=dataset owner_org=None creator_user_id=06d200b6-cd31-4b9e-93fc-c951a5d9e4ef metadata_modified=2014-05-21 11:31:23.744824 private=False state=active revision_id=b2d05bd7-86fb-409d-8d07-85a24d0c2f6c>  

  
Notice the implicit BEGIN, even though we only executed a select. SQLAlchemy will always wrap our sessions in transactions for us when using the ORM. It is this transaction that we generally do not close when we fetch config options from the database, or fetch the site user. Normally this would be ok, but for example when running paster db clean, the metadata gets binded again and the call to reflect causes a new connection to be created as we are already in a transaction. Since the previous transaction has a lock on the database this causes our problem 1, and paster db clean hangs. If you're really interested you can look at the issues on github here(#1656, #1123).

We'll run into our second problem next.

 In [8]: model.Session.registry.has()  
 Out[8]: True  

Our Session registry currently has an active session. Of which our dataset object is a part of, next we run get_site_user.

 In [9]: get_action('get_site_user')({'model': model, 'ignore_auth': True}, {})  
 /home/joe/projects/okf/lib/python2.7/site-packages/sqlalchemy/engine/default.py:475: SAWarning: Unicode type received non-unicode bind param value.  
  processors[key](compiled_params[key])  
 2014-05-21 12:32:28,396 INFO sqlalchemy.engine.base.Engine SELECT "user".password AS user_password, "user".id AS user_id, "user".name AS user_name, "user".openid AS user_openid, "user".fullname AS user_fullname, "user".email AS user_email, "user".apikey AS user_apikey, "user".created AS user_created, "user".reset_key AS user_reset_key, "user".about AS user_about, "user".activity_streams_email_notifications AS user_activity_streams_email_notifications, "user".sysadmin AS user_sysadmin, "user".state AS user_state   
 FROM "user"   
 WHERE "user".name = %(name_1)s OR "user".openid = %(openid_1)s OR "user".id = %(id_1)s ORDER BY "user".name   
  LIMIT %(param_1)s  
 2014-05-21 12:32:28,396 INFO sqlalchemy.engine.base.Engine {'id_1': 'ckan_site_user', 'name_1': 'ckan_site_user', 'param_1': 1, 'openid_1': 'ckan_site_user'}  
 2014-05-21 12:32:28,401 INFO sqlalchemy.engine.base.Engine INSERT INTO "user" (id, name, openid, password, fullname, email, apikey, created, reset_key, about, activity_streams_email_notifications, sysadmin, state) VALUES (%(id)s, %(name)s, %(openid)s, %(password)s, %(fullname)s, %(email)s, %(apikey)s, %(created)s, %(reset_key)s, %(about)s, %(activity_streams_email_notifications)s, %(sysadmin)s, %(state)s)  
 2014-05-21 12:32:28,401 INFO sqlalchemy.engine.base.Engine {'openid': None, 'about': None, 'apikey': '6a717fec-17af-44b7-b10b-c444656341db', 'name': 'ckan_site_user', 'created': datetime.datetime(2014, 5, 21, 12, 32, 28, 401059), 'reset_key': None, 'email': None, 'sysadmin': True, 'activity_streams_email_notifications': False, 'state': u'active', 'fullname': None, 'password': u'', 'id': u'f38f3148-3ab0-4de2-91be-393fad2ca1dd'}  
 2014-05-21 12:32:28,402 INFO sqlalchemy.engine.base.Engine COMMIT  
 Out[9]: {'apikey': '6a717fec-17af-44b7-b10b-c444656341db', 'name': 'ckan_site_user'}  
 In [10]: model.Session.registry.has()  
 Out[10]: False  

get_site_user not only commits, but removes the session and closes the session's connection. Our registry is now closed.

 In [11]: dataset.revision  
 ---------------------------------------------------------------------------  
 DetachedInstanceError: Parent instance <Package at 0x493e850> is not bound to a Session; lazy load operation of attribute 'revision' cannot proceed  

If we now try to use any ORM related features of our object, such as following a relation, we'll get a DetachedInstanceError. In the case of ckanext spatial this is caused by the previous_object becoming detached as get_site_user is called after it. When the previous_object is used later, probably here as it tries to get the HarvestJob object it'll fail, accessing other stuff like previous_object.current will work fine as it doesn't have to goto the database to fetch a related object.

So we ended up having to fix the first problem by closing the transactions by get_site_user and get_system_info, and we could do something like a model.Session.remove() before the drop_all in clean_db, (we do a similar thing in delete_all())

The second problem was fixed by changing get_site_user to only commit and not remove the session.

These two problems were fixed in 2.1.3 and 2.2.1 onwards so hopefully you'll never have to run into them.

This post is basically ckan/ckan#1714