Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

/users endpoint can fail with HTTP 500 when blocked by source_deleter #7093

Open
cfm opened this issue Dec 14, 2023 · 0 comments
Open

/users endpoint can fail with HTTP 500 when blocked by source_deleter #7093

cfm opened this issue Dec 14, 2023 · 0 comments
Labels
bug needs/reproducing

Comments

@cfm
Copy link
Member

cfm commented Dec 14, 2023 •
edited

Description

After deleting many (~10,000) sources from the Journalist Interface, the Journalist API's /users endpoint can fail with HTTP 500 errors, which causes sync to fail.

Steps to Reproduce

Roughly:

  1. Have a lot of sources. (I had 10,002 left over from Release SecureDrop 2.7.0 #6979.)
  2. In the Journalist Interface, delete all source accounts.
  3. Open the SecureDrop Client and log in. Login may fail already, but I was already logged in, so...

Expected Behavior

Normal sync.

Actual Behavior

Sync fails with HTTP 500 errors on /users. 
[Thu Dec 14 21:22:46.583205 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] ERROR:journalist_app:Exception on /api/v1/users [GET]
[Thu Dec 14 21:22:46.583254 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] Traceback (most recent call last):
[Thu Dec 14 21:22:46.583262 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1243, in _execute_context
[Thu Dec 14 21:22:46.583269 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.dialect.do_execute(
[Thu Dec 14 21:22:46.583275 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Thu Dec 14 21:22:46.583282 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     cursor.execute(statement, parameters)
[Thu Dec 14 21:22:46.583288 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] sqlite3.OperationalError: database is locked
[Thu Dec 14 21:22:46.583294 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.583301 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] The above exception was the direct cause of the following exception:
[Thu Dec 14 21:22:46.583307 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.583313 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] Traceback (most recent call last):
[Thu Dec 14 21:22:46.583320 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/app.py", line 2072, in wsgi_app
[Thu Dec 14 21:22:46.583326 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ctx.push()
[Thu Dec 14 21:22:46.583333 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/ctx.py", line 413, in push
[Thu Dec 14 21:22:46.583339 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.session = session_interface.open_session(self.app, self.request)
[Thu Dec 14 21:22:46.583346 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 161, in open_session
[Thu Dec 14 21:22:46.583352 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return ServerSideSession(sid=sid, token=token, initial=data)
[Thu Dec 14 21:22:46.583359 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 27, in __init__
[Thu Dec 14 21:22:46.583365 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.set_user()
[Thu Dec 14 21:22:46.583371 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 50, in set_user
[Thu Dec 14 21:22:46.583393 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.user = Journalist.query.get(self.uid)
[Thu Dec 14 21:22:46.583400 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 959, in get
[Thu Dec 14 21:22:46.583406 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return self._get_impl(ident, loading.load_on_pk_identity)
[Thu Dec 14 21:22:46.583412 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 1069, in _get_impl
[Thu Dec 14 21:22:46.583419 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return db_load_fn(self, primary_key_identity)
[Thu Dec 14 21:22:46.583425 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 282, in load_on_pk_identity
[Thu Dec 14 21:22:46.583432 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return q.one()
[Thu Dec 14 21:22:46.583438 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3275, in one
[Thu Dec 14 21:22:46.583444 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = self.one_or_none()
[Thu Dec 14 21:22:46.583450 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3244, in one_or_none
[Thu Dec 14 21:22:46.583457 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = list(self)
[Thu Dec 14 21:22:46.583463 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3317, in __iter__
[Thu Dec 14 21:22:46.583469 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return self._execute_and_instances(context)
[Thu Dec 14 21:22:46.583476 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3342, in _execute_and_instances
[Thu Dec 14 21:22:46.583482 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     result = conn.execute(querycontext.statement, self._params)
[Thu Dec 14 21:22:46.583488 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 988, in execute
[Thu Dec 14 21:22:46.583495 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return meth(self, multiparams, params)
[Thu Dec 14 21:22:46.583501 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
[Thu Dec 14 21:22:46.583507 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return connection._execute_clauseelement(self, multiparams, params)
[Thu Dec 14 21:22:46.583513 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1101, in _execute_clauseelement
[Thu Dec 14 21:22:46.583520 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = self._execute_context(
[Thu Dec 14 21:22:46.583526 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1247, in _execute_context
[Thu Dec 14 21:22:46.583538 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self._handle_dbapi_exception(
[Thu Dec 14 21:22:46.583544 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
[Thu Dec 14 21:22:46.583551 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     util.raise_from_cause(sqlalchemy_exception, exc_info)
[Thu Dec 14 21:22:46.583557 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
[Thu Dec 14 21:22:46.583564 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     reraise(type(exception), exception, tb=exc_tb, cause=cause)
[Thu Dec 14 21:22:46.583570 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
[Thu Dec 14 21:22:46.583576 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     raise value.with_traceback(tb)
[Thu Dec 14 21:22:46.583582 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1243, in _execute_context
[Thu Dec 14 21:22:46.583589 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.dialect.do_execute(
[Thu Dec 14 21:22:46.583595 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Thu Dec 14 21:22:46.583601 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     cursor.execute(statement, parameters)
[Thu Dec 14 21:22:46.583607 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked
[Thu Dec 14 21:22:46.583615 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] [SQL: SELECT journalists.id AS journalists_id, journalists.uuid AS journalists_uuid, journalists.username AS journalists_username, journalists.first_name AS journalists_first_name, journalists.last_name AS journalists_last_name, journalists.pw_salt AS journalists_pw_salt, journalists.pw_hash AS journalists_pw_hash, journalists.is_admin AS journalists_is_admin, journalists.otp_secret AS journalists_otp_secret, journalists.is_totp AS journalists_is_totp, journalists.hotp_counter AS journalists_hotp_counter, journalists.last_token AS journalists_last_token, journalists.created_on AS journalists_created_on, journalists.last_access AS journalists_last_access, journalists.passphrase_hash AS journalists_passphrase_hash 
[Thu Dec 14 21:22:46.583624 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] FROM journalists 
[Thu Dec 14 21:22:46.583630 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] WHERE journalists.id = ?]
[Thu Dec 14 21:22:46.583636 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] [parameters: (5,)]
[Thu Dec 14 21:22:46.583642 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] (Background on this error at: http://sqlalche.me/e/e3q8)
[Thu Dec 14 21:22:46.584629 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] ERROR:journalist_app:Request finalizing failed with an error while handling an error
[Thu Dec 14 21:22:46.584650 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] Traceback (most recent call last):
[Thu Dec 14 21:22:46.584659 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1243, in _execute_context
[Thu Dec 14 21:22:46.584677 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.dialect.do_execute(
[Thu Dec 14 21:22:46.584685 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Thu Dec 14 21:22:46.584693 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     cursor.execute(statement, parameters)
[Thu Dec 14 21:22:46.584701 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] sqlite3.OperationalError: database is locked
[Thu Dec 14 21:22:46.584709 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.584717 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] The above exception was the direct cause of the following exception:
[Thu Dec 14 21:22:46.584725 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.584733 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] Traceback (most recent call last):
[Thu Dec 14 21:22:46.584741 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/app.py", line 2072, in wsgi_app
[Thu Dec 14 21:22:46.584750 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ctx.push()
[Thu Dec 14 21:22:46.584759 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/ctx.py", line 413, in push
[Thu Dec 14 21:22:46.584767 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.session = session_interface.open_session(self.app, self.request)
[Thu Dec 14 21:22:46.584776 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 161, in open_session
[Thu Dec 14 21:22:46.584785 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return ServerSideSession(sid=sid, token=token, initial=data)
[Thu Dec 14 21:22:46.584793 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 27, in __init__
[Thu Dec 14 21:22:46.584806 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.set_user()
[Thu Dec 14 21:22:46.584815 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 50, in set_user
[Thu Dec 14 21:22:46.584822 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.user = Journalist.query.get(self.uid)
[Thu Dec 14 21:22:46.584828 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 959, in get
[Thu Dec 14 21:22:46.584835 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return self._get_impl(ident, loading.load_on_pk_identity)
[Thu Dec 14 21:22:46.584841 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 1069, in _get_impl
[Thu Dec 14 21:22:46.584848 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return db_load_fn(self, primary_key_identity)
[Thu Dec 14 21:22:46.584854 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/loading.py", line 282, in load_on_pk_identity
[Thu Dec 14 21:22:46.584861 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return q.one()
[Thu Dec 14 21:22:46.584872 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3275, in one
[Thu Dec 14 21:22:46.584879 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = self.one_or_none()
[Thu Dec 14 21:22:46.584885 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3244, in one_or_none
[Thu Dec 14 21:22:46.584892 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = list(self)
[Thu Dec 14 21:22:46.584898 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3317, in __iter__
[Thu Dec 14 21:22:46.584904 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return self._execute_and_instances(context)
[Thu Dec 14 21:22:46.584911 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/orm/query.py", line 3342, in _execute_and_instances
[Thu Dec 14 21:22:46.584917 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     result = conn.execute(querycontext.statement, self._params)
[Thu Dec 14 21:22:46.584924 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 988, in execute
[Thu Dec 14 21:22:46.584930 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return meth(self, multiparams, params)
[Thu Dec 14 21:22:46.584936 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/sql/elements.py", line 287, in _execute_on_connection
[Thu Dec 14 21:22:46.584943 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     return connection._execute_clauseelement(self, multiparams, params)
[Thu Dec 14 21:22:46.584949 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1101, in _execute_clauseelement
[Thu Dec 14 21:22:46.584955 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     ret = self._execute_context(
[Thu Dec 14 21:22:46.584962 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1247, in _execute_context
[Thu Dec 14 21:22:46.584968 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self._handle_dbapi_exception(
[Thu Dec 14 21:22:46.584975 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1466, in _handle_dbapi_exception
[Thu Dec 14 21:22:46.584981 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     util.raise_from_cause(sqlalchemy_exception, exc_info)
[Thu Dec 14 21:22:46.584987 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 383, in raise_from_cause
[Thu Dec 14 21:22:46.584994 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     reraise(type(exception), exception, tb=exc_tb, cause=cause)
[Thu Dec 14 21:22:46.585000 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/util/compat.py", line 128, in reraise
[Thu Dec 14 21:22:46.585007 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     raise value.with_traceback(tb)
[Thu Dec 14 21:22:46.585017 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/base.py", line 1243, in _execute_context
[Thu Dec 14 21:22:46.585024 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.dialect.do_execute(
[Thu Dec 14 21:22:46.585030 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/sqlalchemy/engine/default.py", line 552, in do_execute
[Thu Dec 14 21:22:46.585037 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     cursor.execute(statement, parameters)
[Thu Dec 14 21:22:46.585043 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked
[Thu Dec 14 21:22:46.585050 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] [SQL: SELECT journalists.id AS journalists_id, journalists.uuid AS journalists_uuid, journalists.username AS journalists_username, journalists.first_name AS journalists_first_name, journalists.last_name AS journalists_last_name, journalists.pw_salt AS journalists_pw_salt, journalists.pw_hash AS journalists_pw_hash, journalists.is_admin AS journalists_is_admin, journalists.otp_secret AS journalists_otp_secret, journalists.is_totp AS journalists_is_totp, journalists.hotp_counter AS journalists_hotp_counter, journalists.last_token AS journalists_last_token, journalists.created_on AS journalists_created_on, journalists.last_access AS journalists_last_access, journalists.passphrase_hash AS journalists_passphrase_hash 
[Thu Dec 14 21:22:46.585059 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] FROM journalists 
[Thu Dec 14 21:22:46.585065 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] WHERE journalists.id = ?]
[Thu Dec 14 21:22:46.585071 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] [parameters: (5,)]
[Thu Dec 14 21:22:46.585077 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] (Background on this error at: http://sqlalche.me/e/e3q8)
[Thu Dec 14 21:22:46.585083 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.585089 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] During handling of the above exception, another exception occurred:
[Thu Dec 14 21:22:46.585095 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] 
[Thu Dec 14 21:22:46.585101 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] Traceback (most recent call last):
[Thu Dec 14 21:22:46.585108 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/app.py", line 1540, in finalize_request
[Thu Dec 14 21:22:46.585114 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     response = self.process_response(response)
[Thu Dec 14 21:22:46.585120 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/opt/venvs/securedrop-app-code/lib/python3.8/site-packages/flask/app.py", line 1888, in process_response
[Thu Dec 14 21:22:46.585127 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     self.session_interface.save_session(self, ctx.session, response)
[Thu Dec 14 21:22:46.585133 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]   File "/var/www/securedrop/journalist_app/sessions.py", line 177, in save_session
[Thu Dec 14 21:22:46.585139 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176]     if session.to_destroy:
[Thu Dec 14 21:22:46.585145 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] AttributeError: 'NoneType' object has no attribute 'to_destroy'

root@app:/var/log/apache2# lsof /var/lib/securedrop/db.sqlite                                                                                         
COMMAND PID     USER   FD   TYPE DEVICE SIZE/OFF    NODE NAME                                                                                         
python  564 www-data    3ur  REG  252,0 32129024 1709130 /var/lib/securedrop/db.sqlite                                                                                                                                                                          
root@app:/var/log/apache2# ps aux | grep 564
www-data     564  0.4  2.7 369996 212112 ?       Ss   04:00   4:45 /opt/venvs/securedrop-app-code/bin/python /var/www/securedrop/scripts/source_delete
r --interval 10
root         608  0.0  0.2 107916 20564 ?        Ssl  04:00   0:00 /usr/bin/python3 /usr/share/unattended-upgrades/unattended-upgrade-shutdown --wait-
for-signal
www-data  135644  0.2  0.0  78316  1028 ?        Ss   21:01   0:02 gpg-agent --homedir /var/lib/securedrop/keys --use-standard-socket --daemon
sdadmin   163321  0.0  0.0  12772  5564 ?        S    21:14   0:00 sshd: sdadmin@pts/0
root      167060  0.0  0.0   6448   656 pts/1    S+   21:22   0:00 grep --color=auto 564

systemctl stop securedrop_source_deleter allows sync to proceed normally, albeit subject to the usual bottlenecks.

Comments

This is plain enough:

[Thu Dec 14 21:22:46.583288 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] sqlite3.OperationalError: database is locked

This will take some investigating:

[Thu Dec 14 21:22:46.585145 2023] [wsgi:error] [pid 166864:tid 133758281783040] [remote 127.0.0.1:44176] AttributeError: 'NoneType' object has no attribute 'to_destroy'
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug needs/reproducing
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@cfm