Skip to content

Write a Django Middleware to handle "Database is locked" errors gracefully

When there are too many simultaneous requests to FreedomBox Service (Plinth), or perhaps when the disk I/O is too slow, users see a Database is locked error. It has been discussed how to handle this and was decided that we will show a simplified error asking for users to retry. Handle this error for all requests that user can make and show a nice message by implementing a Django Middleware.

  • Create a Django Middleware for handling such common errors in middleware.py and call it CommonErrorMiddleware. In it handle the error django.db.utils.OperationalError and return response with HTTP 503 status code. This is the correct code when server is unavailable due to load.
  • Install this middleware in the list of all middlewares used by FreedomBox. It should rank higher than all other middleware but less than Django provided middlewares.
  • Customize the error message page shown for 503 HTTP status code by creating 503.html template. In it show the error message "System is possibly under heavy load. Please retry later.". Be sure to internationalize the message. See other error templates as examples.
  • Create a temporary view which just throws the mentioned OperationalError when visited. With this, whenever the temporary view is visited, the error can be seen. Run the application with and without the --develop option on the command line and see the change.
  • Write automated unit test cases for the middleware in test_middleware.py. The tests should cover all branches of the middleware. See tests for other middleware as example.

This issue is nominated for 'Contributor Invite' (ping @dannyhaidar-guest):

  • Task Area: Coding
  • Effort Rating: 3/5
  • Skills Required: Python, pytest, Django Middlware/Views/Templates

Original Description (for reference)

Environment:

  • Software: FreedomBox v0.45.0 testing downloaded on Jan 2, 2019
  • Hardware: Raspberry Pi 2

I've noticed that after installing some apps in FreedomBox, a 500 error page appears. But when you refresh the page, you can see that the app was indeed installed successfully. So this error screen is misleading because, well, the app installs successfully. If users didn't have the idea to refresh the page, they may not know that there actually was no error in the installation.

I've noticed this on the Mumble and Privoxy installs today, and it has occured on other installs in the past.

Here is a screenshot of the error screen:

random_500error

This is a minor UI issue, but it's still a UI issue nonetheless. Why does it happen? And can it be fixed?

Here is the status log that I copied after seeing the error message:

[2019-01-03 19:52:52,058] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:52:56,833] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:52:57,654] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'install', 'privoxy', 'privoxy']

[2019-01-03 19:53:03,286] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:07,878] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:15,208] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:20,016] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:24,879] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:29,584] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:34,401] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:39,013] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:43,667] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:48,301] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:52,943] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:53:57,711] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:02,351] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:06,985] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:11,611] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:16,246] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:20,860] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:25,479] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:30,110] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:34,740] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:39,409] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:44,930] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:49,577] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:54,295] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:54:59,243] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:03,948] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:08,617] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:15,007] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:19,816] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:24,421] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:29,143] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:32,820] plinth.setup INFO Running step for module - privoxy, step - post

[2019-01-03 19:55:32,823] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/firewall', 'get-enabled-services', '--zone', 'internal']

[2019-01-03 19:55:33,825] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:38,184] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/firewall', 'get-enabled-services', '--zone', 'external']

[2019-01-03 19:55:38,717] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:43,329] plinth.modules.firewall INFO Service enabled - privoxy, True

[2019-01-03 19:55:43,331] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/firewall', 'add-service', 'privoxy', '--zone', 'internal']

[2019-01-03 19:55:43,582] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:48,410] plinth.actions INFO Executing command - ['sudo', '-n', '/usr/share/plinth/actions/packages', 'is-package-manager-busy']

[2019-01-03 19:55:52,688] plinth.setup INFO Running step for module - privoxy, step - post

[2019-01-03 19:55:58,251] django.request ERROR Internal Server Error: /plinth/apps/privoxy/ Traceback (most recent call last): File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute return self.cursor.execute(sql, params) File "/usr/lib/python3/dist-packages/django/db/backends/sqlite3/base.py", line 328, in execute return Database.Cursor.execute(self, query, params) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/usr/lib/python3/dist-packages/django/core/handlers/exception.py", line 41, in inner response = get_response(request) File "/usr/lib/python3/dist-packages/django/core/handlers/base.py", line 178, in _get_response response = middleware_method(request, callback, callback_args, callback_kwargs) File "/usr/lib/python3/dist-packages/stronghold/middleware.py", line 29, in process_view if conf.STRONGHOLD_USER_TEST_FUNC(request.user)
File "/usr/lib/python3/dist-packages/stronghold/conf.py", line 17, in is_authenticated return user.is_authenticated() File "/usr/lib/python3/dist-packages/django/utils/functional.py", line 238, in inner self._setup() File "/usr/lib/python3/dist-packages/django/utils/functional.py", line 386, in _setup self._wrapped = self._setupfunc() File "/usr/lib/python3/dist-packages/django/contrib/auth/middleware.py", line 24, in request.user = SimpleLazyObject(lambda: get_user(request)) File "/usr/lib/python3/dist-packages/django/contrib/auth/middleware.py", line 12, in get_user request._cached_user = auth.get_user(request) File "/usr/lib/python3/dist-packages/django/contrib/auth/init.py", line 218, in get_user user = backend.get_user(user_id) File "/usr/lib/python3/dist-packages/django/contrib/auth/backends.py", line 102, in get_user user = UserModel._default_manager.get(pk=user_id) File "/usr/lib/python3/dist-packages/django/db/models/manager.py", line 85, in manager_method return getattr(self.get_queryset(), name)(*args, **kwargs) File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 374, in get num = len(clone) File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 232, in len self._fetch_all() File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 1121, in _fetch_all self._result_cache = list(self._iterable_class(self)) File "/usr/lib/python3/dist-packages/django/db/models/query.py", line 53, in iter results = compiler.execute_sql(chunked_fetch=self.chunked_fetch) File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 899, in execute_sql raise original_exception File "/usr/lib/python3/dist-packages/django/db/models/sql/compiler.py", line 889, in execute_sql cursor.execute(sql, params) File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute return self.cursor.execute(sql, params) File "/usr/lib/python3/dist-packages/django/db/utils.py", line 94, in exit six.reraise(dj_exc_type, dj_exc_value, traceback) File "/usr/lib/python3/dist-packages/django/utils/six.py", line 685, in reraise raise value.with_traceback(tb) File "/usr/lib/python3/dist-packages/django/db/backends/utils.py", line 64, in execute return self.cursor.execute(sql, params) File "/usr/lib/python3/dist-packages/django/db/backends/sqlite3/base.py", line 328, in execute return Database.Cursor.execute(self, query, params) django.db.utils.OperationalError: database is locked

Edited by Sunil Mohan Adapa