importlater() causes a blocking condition

Hi,

an application of mine has been working fine up to SQLA 0.6.5, but from 0.6.6 on* "database access" blocks in about one of three application runs. When the "database access" blocks, the rest of the application that is up&running to this point and does not use the database, continues to work. Everything else comes to a halt. This halt occurs with the first database actions performed right after the application startup. The application will not shut down (gracefully at least) and has to be terminated.

The application works with many threads that are spawned during startup after the applcation basics are set up. Many of those work with the database. It's not unlikely that a few happen to start their database activity at the same time.

After all kinds of debugging I ended up comparing 0.6.5 to 0.6.6 for a second time and the appearance of importlater() caught my eye. In the past I found that python, under certain conditions, can block/deadlock during an import. I extended importlater()'s _il_module property to print

    print >> sys.stderr, u"from %s import %s" % (self._il_path, self._il_addtl)

before importing and, as the finally-step of an added try-finally construct print

    print >> sys.stderr, u"from %s import %s done" % (self._il_path, self._il_addtl)

after the import.

In every case, where the application did block in a run, the result was identical:

from sqlalchemy.engine import url
from sqlalchemy.engine import url done
from sqlalchemy.orm import mapperlib
from sqlalchemy.orm import mapperlib done
from sqlalchemy.orm import properties
from sqlalchemy.orm import properties done
from sqlalchemy.sql import util
from sqlalchemy.sql import util done
from sqlalchemy.sql import functions
from sqlalchemy.sql import functions done
from sqlalchemy.orm import util

In every case, where the application did NOT block in a run, the result was identical:

from sqlalchemy.engine import url
from sqlalchemy.engine import url done
from sqlalchemy.orm import mapperlib
from sqlalchemy.orm import mapperlib done
from sqlalchemy.orm import properties
from sqlalchemy.orm import properties done
from sqlalchemy.sql import util
from sqlalchemy.sql import util done
from sqlalchemy.sql import functions
from sqlalchemy.sql import functions done
from sqlalchemy.orm import util
from sqlalchemy.orm import util done

It appears that from sqlalchemy.orm import util can cause the interpreter** to block at times. This import is only performed once in all sqlalchemy 0.6.6 code, in orm/attributes.py.

I've been trying to isolate the issue and build a small environment to reproduce it. Unfortunately I wasn't able to cause the import at all. I'm not sure under which conditions it is performed and how I have to set up my entities for it to occur. A traceback.print_stack() in orm/attributes, right before

            self.is_equal = mapperutil.identity_equal

gave the following stack trace:

  File "/usr/lib/python2.6/threading.py", line 504, in __bootstrap
    self.__bootstrap_inner()
  File "/usr/lib/python2.6/threading.py", line 532, in __bootstrap_inner
    self.run()
  File "include/xx/xxxxxxxx/xxxx/xxxx.py", line 239, in run_with_except_hook
    run_old(*args, **kw)
  File "include/xx/xxxxxxxx/xxx/xxxxxxx/xxxxx/xxxxxx.py", line 38, in run
    self._process_spool()
  File "include/xx/xxxxxxxx/xxx/xxxxxxx/xxxxx/xxxxxx.py", line 58, in _process_spool
    self._try_to_process_spool()
  File "include/xx/xxxxxxxx/xxx/xxxxxxx/xxxxx/xxxxxx.py", line 70, in _try_to_process_spool
    self._fetch_spool_entries()
  File "include/xx/xxxxxxxx/xxx/xxxxxxx/xxxxx/xxxxxx.py", line 75, in _fetch_spool_entries
    query = self._session.query(MyEntity).\
  File "include/sqlalchemy/orm/session.py", line 862, in query
    return self._query_cls(entities, self, **kwargs)
  File "include/sqlalchemy/orm/query.py", line 107, in __init__
    self._set_entities(entities)
  File "include/sqlalchemy/orm/query.py", line 116, in _set_entities
    self._setup_aliasizers(self._entities)
  File "include/sqlalchemy/orm/query.py", line 131, in _setup_aliasizers
    _entity_info(entity)
  File "include/sqlalchemy/orm/util.py", line 548, in _entity_info
    mapper = mapper.compile()
  File "include/sqlalchemy/orm/mapper.py", line 816, in compile
    mapper._post_configure_properties()
  File "include/sqlalchemy/orm/mapper.py", line 849, in _post_configure_properties
    prop.post_instrument_class(self)
  File "include/sqlalchemy/orm/interfaces.py", line 688, in post_instrument_class
    self.strategy.init_class_attribute(mapper)
  File "include/sqlalchemy/orm/strategies.py", line 404, in init_class_attribute
    not self.use_get,
  File "include/sqlalchemy/orm/strategies.py", line 70, in _register_attribute
    **kw
  File "include/sqlalchemy/orm/attributes.py", line 1497, in register_attribute_impl
    impl = ScalarObjectAttributeImpl(class_, key, callable_, **kw)
  File "include/sqlalchemy/orm/attributes.py", line 573, in __init__
    print_stack()

I found that forcing the lazy import

    from sqlalchemy.orm.attributes import mapperutil
    mapperutil.identity_equal

to be performed before the first database operation and before all threads are started, will work around the issue.

Let me know if I can provide further details.

Kind regards,[BR] Thomas Wiebe

tested with 0.6.6, 0.6.7, 0.6.8, 0.7.2[BR] ** tested with python 2.5.4 and 2.6.5 on x86_64 Linux machines

Comments (19)