transaction/config issue ?

[revolunet]

Hi, i'm trying to setup kinto-emailer for new records notifications. I've added it to KINTO_INCLUDES and created MAIL_DEFAULT_SENDER and MAIL_HOST as environment variables, but as soon as some notification is triggered i get this error message :

Unable to notify
Traceback (most recent call last):
  File "/app/kinto/core/events.py", line 181, in _notify_resource_events_after
    request.registry.notify(event)
  File "/usr/local/lib/python3.7/site-packages/pyramid/registry.py", line 109, in notify
    [_ for _ in self.subscribers(events, None)]
  File "/usr/local/lib/python3.7/site-packages/zope/interface/registry.py", line 448, in subscribers
    return self.adapters.subscribers(objects, provided)
  File "/usr/local/lib/python3.7/site-packages/zope/interface/adapter.py", line 619, in subscribers
    subscription(*objects)
  File "/usr/local/lib/python3.7/site-packages/pyramid/config/adapters.py", line 129, in subscriber_wrapper
    return derived_subscriber(*arg)
  File "/usr/local/lib/python3.7/site-packages/pyramid/config/adapters.py", line 101, in derived_subscriber
    return subscriber(arg[0])
  File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 58, in send_notification
    messages += get_messages(storage, _context)
  File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 118, in get_messages
    hooks = _get_emailer_hooks(storage, context)
  File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 78, in _get_emailer_hooks
    object_id=collection_id)
  File "/app/kinto/core/decorators.py", line 70, in wrapper
    return func(*args, **new_kwargs)
  File "/app/kinto/core/storage/postgresql/__init__.py", line 339, in get
    result = conn.execute(query, placeholders)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 1291, in execute
    return self._connection_for_bind(bind, close_with_result=True).execute(
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 1147, in _connection_for_bind
    engine, execution_options
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 458, in _connection_for_bind
    self.session.dispatch.after_begin(self.session, self, conn)
  File "/usr/local/lib/python3.7/site-packages/sqlalchemy/event/attr.py", line 261, in __call__
    fn(*args, **kw)
  File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 269, in after_begin
    session, self.initial_state, self.transaction_manager, self.keep_session
  File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 234, in join_transaction
    session, initial_state, transaction_manager, keep_session=keep_session
  File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 89, in __init__
    transaction_manager.get().join(self)
  File "/usr/local/lib/python3.7/site-packages/transaction/_transaction.py", line 191, in join
    Status.ACTIVE, Status.DOOMED, self.status))
ValueError: expected txn status 'Active' or 'Doomed', but it's 'Committed'

So looks like the notification is triggered but something is missing in my setup. Hard to tell what with this error though.

Any guidance on how to debug this ?

[Natim]

It seems that by the time your notification is sent the connection to the database was committed and sqlalchemy can't use the connection anymore to fetch the notification configuration. To be honest I've never seen this error message before. I would find out where the commit happens and try to close the connection at the same time so that the sqlalchemy pooler reopen a new connection. What is your kinto database configuration? Maybe try to set more than one connection in the connection pool? Le ven. 27 nov. 2020 à 08:52, Julien Bouquillon <[email protected]> a écrit :

…

Hi, i'm trying to setup kinto-emailer for new records notifications. I've added it to KINTO_INCLUDES and created MAIL_DEFAULT_SENDER and MAIL_HOST as environment variables, but as soon as some notification is triggered i get this error message : Unable to notifyTraceback (most recent call last): File "/app/kinto/core/events.py", line 181, in _notify_resource_events_after request.registry.notify(event) File "/usr/local/lib/python3.7/site-packages/pyramid/registry.py", line 109, in notify [_ for _ in self.subscribers(events, None)] File "/usr/local/lib/python3.7/site-packages/zope/interface/registry.py", line 448, in subscribers return self.adapters.subscribers(objects, provided) File "/usr/local/lib/python3.7/site-packages/zope/interface/adapter.py", line 619, in subscribers subscription(*objects) File "/usr/local/lib/python3.7/site-packages/pyramid/config/adapters.py", line 129, in subscriber_wrapper return derived_subscriber(*arg) File "/usr/local/lib/python3.7/site-packages/pyramid/config/adapters.py", line 101, in derived_subscriber return subscriber(arg[0]) File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 58, in send_notification messages += get_messages(storage, _context) File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 118, in get_messages hooks = _get_emailer_hooks(storage, context) File "/usr/local/lib/python3.7/site-packages/kinto_emailer/__init__.py", line 78, in _get_emailer_hooks object_id=collection_id) File "/app/kinto/core/decorators.py", line 70, in wrapper return func(*args, **new_kwargs) File "/app/kinto/core/storage/postgresql/__init__.py", line 339, in get result = conn.execute(query, placeholders) File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 1291, in execute return self._connection_for_bind(bind, close_with_result=True).execute( File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 1147, in _connection_for_bind engine, execution_options File "/usr/local/lib/python3.7/site-packages/sqlalchemy/orm/session.py", line 458, in _connection_for_bind self.session.dispatch.after_begin(self.session, self, conn) File "/usr/local/lib/python3.7/site-packages/sqlalchemy/event/attr.py", line 261, in __call__ fn(*args, **kw) File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 269, in after_begin session, self.initial_state, self.transaction_manager, self.keep_session File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 234, in join_transaction session, initial_state, transaction_manager, keep_session=keep_session File "/usr/local/lib/python3.7/site-packages/zope/sqlalchemy/datamanager.py", line 89, in __init__ transaction_manager.get().join(self) File "/usr/local/lib/python3.7/site-packages/transaction/_transaction.py", line 191, in join Status.ACTIVE, Status.DOOMED, self.status))ValueError: expected txn status 'Active' or 'Doomed', but it's 'Committed' So looks like the notification is triggered but something is missing in my setup. Hard to tell what with this error though. Any guidance on how to debug this ? — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#232>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABYATJFRHCNBYZUIKXRUJ3SR5LCLANCNFSM4UESOYEA> .

[revolunet]

I run tests with a basic docker-compose with postgres:10 and kinto/kinto-server:14.1.3 and these env variables :

KINTO_STORAGE_BACKEND: kinto.core.storage.postgresql
KINTO_STORAGE_URL: postgresql://postgres:postgres@postgres/postgres
KINTO_MULTIAUTH_POLICIES: "account basicauth"
KINTO_INCLUDES: "kinto.plugins.accounts kinto.plugins.admin kinto_emailer"
MAIL_DEFAULT_SENDER: "[email protected]"
MAIL_HOST: "smtp.wanadoo.fr"

Looks like the default pool size is 25 🤔

[Natim]

Can you try to downgrade the transaction package to 2.4.0 and see if you still have the issue?

[revolunet]

Woot, pip install --upgrade transaction==2.4 solves this error, thanks a ton !!

[Natim]

Well I'm not sure it's sufficient to close the issue but at least we nailed it to the root cause.