Stale Data Error - Githubissues

lnielsen commented 3 years ago

[pid: 12|app: 0|req: 11/66] 10.51.106.37 () {56 vars in 939 bytes} [Tue Aug 31 12:40:18 2021] POST /api/records/e76fk-2mv80/draft/actions/publish => generated 182 bytes in 107 msecs (HTTP/1.1 500) 15 headers in 872 bytes (1 switches on core 0)
[2021-08-31 12:40:24,751] ERROR in app: Exception on /records/c4t4e-ks019/draft/actions/publish [POST]
Traceback (most recent call last):
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/app.py", line 2447, in wsgi_app
    response = self.full_dispatch_request()
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/app.py", line 1952, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask_restful/__init__.py", line 271, in error_router
    return original_handler(e)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/app.py", line 1821, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/_compat.py", line 39, in reraise
    raise value
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/app.py", line 1950, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask/app.py", line 1936, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask_resources/resources.py", line 65, in view
    return view_meth()
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask_resources/content_negotiation.py", line 116, in inner_content_negotiation
    return f(*args, **kwargs)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask_resources/parsers/decorators.py", line 51, in inner
    return f(self, *args, **kwargs)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/flask_resources/responses.py", line 39, in inner
    res = f(*args, **kwargs)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_drafts_resources/resources/records/resource.py", line 140, in publish
    g.identity,
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_drafts_resources/services/records/service.py", line 283, in publish
    component.publish(identity, draft=draft, record=record)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_drafts_resources/services/records/components/files.py", line 144, in publish
    self._publish_new(identity, draft, record)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_drafts_resources/services/records/components/files.py", line 115, in _publish_new
    draft.files.delete_all(remove_obj=False)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_records_resources/records/systemfields/files/manager.py", line 73, in inner
    return func(self, *args, **kwargs)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_records_resources/records/systemfields/files/manager.py", line 205, in delete_all
    self.delete(key, remove_obj=remove_obj)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_records_resources/records/systemfields/files/manager.py", line 73, in inner
    return func(self, *args, **kwargs)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_records_resources/records/systemfields/files/manager.py", line 185, in delete
    rf.delete(force=True)
  File "/opt/rh/rh-python36/root/usr/lib/python3.6/site-packages/invenio_records/api.py", line 512, in delete
    db.session.merge(self.model)
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 614, in __exit__
    self.rollback()
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    with_traceback=exc_tb,
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 611, in __exit__
    self.commit()
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 504, in commit
    self._prepare_impl()
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 483, in _prepare_impl
    self.session.flush()
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2540, in flush
    self._flush(objects)
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2682, in _flush
    transaction.rollback(_capture_exception=True)
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/util/langhelpers.py", line 70, in __exit__
    with_traceback=exc_tb,
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/util/compat.py", line 182, in raise_
    raise exception
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/session.py", line 2642, in _flush
    flush_context.execute()
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 422, in execute
    rec.execute(self)
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/unitofwork.py", line 624, in execute
    uow,
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 348, in delete_obj
    delete,
  File "/opt/rh/rh-python36/root/usr/lib64/python3.6/site-packages/sqlalchemy/orm/persistence.py", line 1372, in _emit_delete_statements
    % (table.description, expected, rows_matched)
sqlalchemy.orm.exc.StaleDataError: DELETE statement on table 'rdm_drafts_files' expected to delete 1 row(s); 0 were matched.  Please set confirm_deleted_rows=False within the mapper configuration to prevent this warning.

fenekku commented 3 years ago

This problem is typically observed in an import setting where drafts are associated files and then published.

What we've observed so far A race condition happens in that scenario:

when a file is uploaded (files_service.commit()) an asynchronous task extract_file_metadata is launched that extracts metadata and stores it back on the rdm_drafts_files row.
when a draft is published, the corresponding rdm_drafts_files row is deleted.

Each of these actions use a version_id for selection and in this case the deletion can't complete because the version_id it has is staled compared to the version_id of the rdm_drafts_files row in the DB that has now been updated.

The proposed solution is to have a means to specify that file_service.extract_file_metadata() should be called synchronously when committing a file.

github-actions[bot] commented 3 years ago

This issue was automatically marked as stale.

inveniosoftware / invenio-rdm-records

Stale Data Error #809