deduplication of events doesn't work for wrapped events

[Leonardo Rossi]

update: this specifically hits the _stored_in_collection assertion because the check for if event_key._listen_fn not in self.listeners fails for an event key with wrapping.

I'm using Invenio 2.0 and try to replace old version of SQLAlchemy 0.8.7 with the last 0.9.7. The utility to automaticaly create the db works (inveniomanage database recreate --yes-i-know).

But when I start tests with: python setup.py test

It return me a error:

test_fisrt_blueprint (invenio.testsuite.test_ext_template.TemplateLoaderCase) ... --------------------------------------------------------------------------------
ERROR in wrappers [/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/logging/wrappers.py:310]:

--------------------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/legacy/__init__.py", line 124, in __call__
    response = self.app.full_dispatch_request()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1470, in full_dispatch_request
    self.try_trigger_before_first_request_functions()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1497, in try_trigger_before_first_request_functions
    func()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/views.py", line 264, in invoke_email_alert_register
    email_alert_register()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/models.py", line 202, in email_alert_register
    event.listen(MsgMESSAGE, 'after_insert', email_alert)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/api.py", line 63, in listen
    _event_key(target, identifier, fn).listen(*args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 187, in listen
    self.dispatch_target.dispatch._listen(self, *args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/orm/events.py", line 547, in _listen
    event_key.base_listen(**kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 226, in base_listen
    for_modify(target.dispatch).append(self, propagate)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/attr.py", line 328, in append
    event_key.append_to_list(self, self.listeners)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 237, in append_to_list
    _stored_in_collection(self, owner)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 74, in _stored_in_collection
    assert dispatch_reg[owner_ref] == listen_ref
AssertionError

In /home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/views.py (row 264)

# Registration of email_alert invoked from blueprint
# in order to use before_app_first_request.
# Reading config CFG_WEBMESSAGE_EMAIL_ALERT
# required app context.
@blueprint.before_app_first_request
def invoke_email_alert_register():
    email_alert_register()

In /home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/models.py (row 202)

# Registration of email_alert invoked from blueprint
# in order to use before_app_first_request.
# Reading config CFG_WEBMESSAGE_EMAIL_ALERT
# required app context.
def email_alert_register():
    if cfg['CFG_WEBMESSAGE_EMAIL_ALERT']:
        from sqlalchemy import event
        # Register after insert callback.
        event.listen(MsgMESSAGE, 'after_insert', email_alert)

Someone can help me? :) (Sorry, this is my first issues and I don't know how to set "kind", etc... T_T)

Installed:

• -e git+https://github.com/mitsuhiko/flask-sqlalchemy@c7eccba63314f3ea77e2c6217d3d3c8b0d2552fd#egg=Flask_SQLAlchemy-2.0
• MySQL-python==1.2.5
• SQLAlchemy==0.9.7
• SQLAlchemy-Utils==0.23.5

[Mike Bayer]

well, I'm hoping to see what the very simple condition that causes this is, however, it's taking me quite a while to install this beast of an application and actually get just that one test to run. the installer started looking for an apache server, thankfully it seems to have installed the tables at least, and now its looking for a redis server.

are you the developer of invenio?

[Mike Bayer]

Sorry, the test in question passes fine for me once I correct for issue #3200. I'd need the invenio devs to provide more succinct detail here.

[Leonardo Rossi]

Hi Mike,

thank you for your help! :)

I'm working on my branch (of "pu" branch) here: https://github.com/hachreak/invenio/tree/fix_deprecated_arguments_constructor_sqlalchemy

I try to fix compatibility problems with SQLAchemy >= 0.9.*

You can try to use invenio-devscripts to create a virtual machine and start tests: https://github.com/tiborsimko/invenio-devscripts

You can follow this steps to reproduce the errors:

1. create Vagrantfile (as Tibor wrote in readme of invenio-devscripts)
2. vagrant up
3. vagrant ssh
4. Execute:

wget https://raw.githubusercontent.com/tiborsimko/invenio-devscripts/master/invenio2-kickstart
chmod u+x ./invenio2-kickstart
./invenio2-kickstart --yes-i-know --yes-i-really-know
source $(which virtualenvwrapper.sh)
workon invenio2
cdvirtualenv src/invenio
git remote add hachreak git://github.com/hachreak/invenio.git
git fetch hachreak
git checkout fix_deprecated_arguments_constructor_sqlalchemy
pip install -r requirements.txt --exists-action i
pip install `pip freeze -l | cut --fields=1 -d = -|grep -v ^-e` --upgrade
pip install -e .
sudo pip install python-gettext
inveniomanage database init --yes-i-know
inveniomanage database create
python setup.py test

[Leonardo Rossi]

I wrote a script to create an testing environment ready-to-use to make reproducible my fix-branch, and with it, errors generated from tests:

invenio2-test-branch.sh

[Mike Bayer]

Im sorrry i dont understand what "repostiory URL" and "Branch name" are. I really just need a simple test case. I tried what you have above, since i have no idea what we're doing:

#!


../invenio2-test-branch.sh git://github.com/hachreak/invenio.git hachreak
[ERROR] Unable to find the 'hachreak'

[Leonardo Rossi]

invenio2-test-branch.sh git://github.com/hachreak/invenio.git fix_deprecated_arguments_constructor_sqlalchemy

[Leonardo Rossi]

It's the branch in my pull request here: https://github.com/inveniosoftware/invenio/pull/2263

[Mike Bayer]

please email me an ssh key at classic at zzzcomputing.com and i will put you on an amazon host that you can get this working on for me. there's no apt-get for virtualbox

[Mike Bayer]

also can you perhaps try this patch for me? this might get at what is happening and would be OK:

diff --git a/lib/sqlalchemy/event/registry.py b/lib/sqlalchemy/event/registry.py
index ba2f671..134ef86 100644
--- a/lib/sqlalchemy/event/registry.py
+++ b/lib/sqlalchemy/event/registry.py
@@ -71,7 +71,9 @@ def _stored_in_collection(event_key, owner):
     listen_ref = weakref.ref(event_key._listen_fn)

     if owner_ref in dispatch_reg:
-        assert dispatch_reg[owner_ref] == listen_ref
+        if dispatch_reg[owner_ref] is not listen_ref:
+            assert dispatch_reg[owner_ref]() is None
+            dispatch_reg[owner_ref] = listen_ref
     else:
         dispatch_reg[owner_ref] = listen_ref

[Leonardo Rossi]

I sent the email to classic... with my ssh key.

I tried this patch, but now it return me:

test_update_list_element (invenio.modules.deposit.testsuite.test_deposit_form.WebDepositFormTest) ... ok
test_create_delete (invenio.modules.deposit.testsuite.test_type_simplerecord.SimpleRecordTest) ... FAIL
test_registration (invenio.modules.deposit.testsuite.test_type_simplerecord.SimpleRecordTest) ... --------------------------------------------------------------------------------
ERROR in wrappers [/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/logging/wrappers.py:310]:

--------------------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/legacy/__init__.py", line 124, in __call__
    response = self.app.full_dispatch_request()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1470, in full_dispatch_request
    self.try_trigger_before_first_request_functions()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1497, in try_trigger_before_first_request_functions
    func()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/views.py", line 264, in invoke_email_alert_register
    email_alert_register()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/models.py", line 202, in email_alert_register
    event.listen(MsgMESSAGE, 'after_insert', email_alert)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/api.py", line 63, in listen
    _event_key(target, identifier, fn).listen(*args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 191, in listen
    self.dispatch_target.dispatch._listen(self, *args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/orm/events.py", line 547, in _listen
    event_key.base_listen(**kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 230, in base_listen
    for_modify(target.dispatch).append(self, propagate)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/attr.py", line 328, in append
    event_key.append_to_list(self, self.listeners)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 241, in append_to_list
    _stored_in_collection(self, owner)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 77, in _stored_in_collection
    assert dispatch_reg[owner_ref]() is None
AssertionError
ERROR:invenio.base:
Traceback (most recent call last):
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/legacy/__init__.py", line 124, in __call__
    response = self.app.full_dispatch_request()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1470, in full_dispatch_request
    self.try_trigger_before_first_request_functions()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1497, in try_trigger_before_first_request_functions
    func()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/views.py", line 264, in invoke_email_alert_register
    email_alert_register()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/models.py", line 202, in email_alert_register
    event.listen(MsgMESSAGE, 'after_insert', email_alert)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/api.py", line 63, in listen
    _event_key(target, identifier, fn).listen(*args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 191, in listen
    self.dispatch_target.dispatch._listen(self, *args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/orm/events.py", line 547, in _listen
    event_key.base_listen(**kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 230, in base_listen
    for_modify(target.dispatch).append(self, propagate)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/attr.py", line 328, in append
    event_key.append_to_list(self, self.listeners)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 241, in append_to_list
    _stored_in_collection(self, owner)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 77, in _stored_in_collection
    assert dispatch_reg[owner_ref]() is None
AssertionError
FAIL
Traceback (most recent call last):
  File "setup.py", line 302, in <module>
    'install_lib': _install_lib,
  File "/usr/lib/python2.7/distutils/core.py", line 151, in setup
    dist.run_commands()
  File "/usr/lib/python2.7/distutils/dist.py", line 953, in run_commands
    self.run_command(cmd)
  File "/usr/lib/python2.7/distutils/dist.py", line 972, in run_command
    cmd_obj.run()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/setuptools/command/test.py", line 146, in run
    self.with_project_on_sys_path(self.run_tests)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/setuptools/command/test.py", line 127, in with_project_on_sys_path
    func()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/setuptools/command/test.py", line 167, in run_tests
    testRunner=self._resolve_as_ep(self.test_runner),
  File "/usr/lib/python2.7/unittest/main.py", line 95, in __init__
    self.runTests()
  File "/usr/lib/python2.7/unittest/main.py", line 232, in runTests
    self.result = testRunner.run(self.test)
  File "/usr/lib/python2.7/unittest/runner.py", line 151, in run
    test(result)
  File "/usr/lib/python2.7/unittest/suite.py", line 70, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python2.7/unittest/suite.py", line 108, in run
    test(result)
  File "/usr/lib/python2.7/unittest/suite.py", line 70, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python2.7/unittest/suite.py", line 108, in run
    test(result)
  File "/usr/lib/python2.7/unittest/suite.py", line 70, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python2.7/unittest/suite.py", line 108, in run
    test(result)
  File "/usr/lib/python2.7/unittest/suite.py", line 70, in __call__
    return self.run(*args, **kwds)
  File "/usr/lib/python2.7/unittest/suite.py", line 108, in run
    test(result)
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio-demosite/Flask_Testing-0.4.2-py2.7.egg/flask_testing/utils.py", line 94, in __call__
    self._post_teardown()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio-demosite/Flask_Testing-0.4.2-py2.7.egg/flask_testing/utils.py", line 123, in _post_teardown
    self._ctx.pop()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/ctx.py", line 357, in pop
    % (rv, self)
AssertionError: Popped wrong request context.  (<RequestContext 'http://0.0.0.0:8080/deposit/' [GET] of invenio.base> instead of <RequestContext 'http://localhost/' [GET] of invenio.base>)

[Mike Bayer]

can you try this one please:

diff --git a/lib/sqlalchemy/event/registry.py b/lib/sqlalchemy/event/registry.py
index ba2f671..d40aa19 100644
--- a/lib/sqlalchemy/event/registry.py
+++ b/lib/sqlalchemy/event/registry.py
@@ -71,7 +71,10 @@ def _stored_in_collection(event_key, owner):
     listen_ref = weakref.ref(event_key._listen_fn)

     if owner_ref in dispatch_reg:
-        assert dispatch_reg[owner_ref] == listen_ref
+        if dispatch_reg[owner_ref] is not listen_ref:
+            assert dispatch_reg[owner_ref]() is None or \
+                dispatch_reg[owner_ref]() is event_key._listen_fn
+            dispatch_reg[owner_ref] = listen_ref
     else:
         dispatch_reg[owner_ref] = listen_ref

[Leonardo Rossi]

======================================================================
FAIL: test_login_handler (invenio.testsuite.test_ext_sso.TestSSO)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/testsuite/test_ext_sso.py", line 97, in test_login_handler
    run(data, expected_data)
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/testsuite/test_ext_sso.py", line 69, in run
    c.get(self.app.config['SSO_LOGIN_URL'])
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/werkzeug/test.py", line 762, in get
    return self.open(*args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/testing.py", line 108, in open
    follow_redirects=follow_redirects)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/werkzeug/test.py", line 736, in open
    response = self.run_wsgi_app(environ, buffered=buffered)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/werkzeug/test.py", line 659, in run_wsgi_app
    rv = run_wsgi_app(self.application, environ, buffered=buffered)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/werkzeug/test.py", line 855, in run_wsgi_app
    app_iter = app(environ, start_response)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1836, in __call__
    return self.wsgi_app(environ, start_response)
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/legacy/__init__.py", line 128, in __call__
    response = self.app.handle_exception(e)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask_restful/__init__.py", line 258, in error_router
    return original_handler(e)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1403, in handle_exception
    reraise(exc_type, exc_value, tb)
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/ext/legacy/__init__.py", line 124, in __call__
    response = self.app.full_dispatch_request()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1470, in full_dispatch_request
    self.try_trigger_before_first_request_functions()
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/flask/app.py", line 1497, in try_trigger_before_first_request_functions
    func()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/views.py", line 264, in invoke_email_alert_register
    email_alert_register()
  File "/home/vagrant/.virtualenvs/invenio2/src/invenio/invenio/modules/messages/models.py", line 202, in email_alert_register
    event.listen(MsgMESSAGE, 'after_insert', email_alert)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/api.py", line 63, in listen
    _event_key(target, identifier, fn).listen(*args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 191, in listen
    self.dispatch_target.dispatch._listen(self, *args, **kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/orm/events.py", line 547, in _listen
    event_key.base_listen(**kw)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 230, in base_listen
    for_modify(target.dispatch).append(self, propagate)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/attr.py", line 328, in append
    event_key.append_to_list(self, self.listeners)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 241, in append_to_list
    _stored_in_collection(self, owner)
  File "/home/vagrant/.virtualenvs/invenio2/local/lib/python2.7/site-packages/sqlalchemy/event/registry.py", line 77, in _stored_in_collection
    dispatch_reg[owner_ref]() is event_key._listen_fn
AssertionError

[Mike Bayer]

really terrible. get onto the box I sent you, you dont need to use vagrant it's a micro, just install everything fully.

[Mike Bayer]

nevermind! I reproduced this. I have the cause now, thanks!

[Leonardo Rossi]

Do you use my branch (with my latest commit of today)? Because I downgrade SQLAlchemy version. You can know which version:

pip freeze | grep -i sql

If it's the 0.8.7 version, try to manually change setup.py

[Mike Bayer]

• Fixed bug that affected many classes of event, particularly ORM events but also engine events, where the usual logic of "de duplicating" a redundant call to :func:.event.listen with the same arguments would fail, for those events where the listener function is wrapped. An assertion would be hit within registry.py. This assertion has now been integrated into the deduplication check, with the added bonus of a simpler means of checking deduplication across the board. fixes #3199

→ <<cset 9ae4db27b993>>

[Mike Bayer]

• Fixed bug that affected many classes of event, particularly ORM events but also engine events, where the usual logic of "de duplicating" a redundant call to :func:.event.listen with the same arguments would fail, for those events where the listener function is wrapped. An assertion would be hit within registry.py. This assertion has now been integrated into the deduplication check, with the added bonus of a simpler means of checking deduplication across the board. fixes #3199

Conflicts: lib/sqlalchemy/event/registry.py test/base/test_events.py

→ <<cset 322e2568fb37>>

[Mike Bayer]

fixed for 0.9.8.

[Leonardo Rossi]

yep! It seems to works for me! :D When do you officially publish 0.9.8? :)