From fdc6ae24bcedfb1d3890fa655947e1b6587bc6e3 Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Sat, 8 Jun 2024 18:38:44 -0700 Subject: [PATCH 1/8] Adds test class for checking query durations This is a first pass and I wrote it specifically so that it would fail on the query in test_book.py --- bookwyrm/tests/query_logger.py | 39 +++++++++++++++++++++++++ bookwyrm/tests/views/books/test_book.py | 16 +++++++--- 2 files changed, 51 insertions(+), 4 deletions(-) create mode 100644 bookwyrm/tests/query_logger.py diff --git a/bookwyrm/tests/query_logger.py b/bookwyrm/tests/query_logger.py new file mode 100644 index 0000000000..6474ff41b2 --- /dev/null +++ b/bookwyrm/tests/query_logger.py @@ -0,0 +1,39 @@ +""" Log query runtimes for testing """ +import time + + +class QueryLogger: + """Returns the sql and duration for any query run + Taken wholesale from: + https://docs.djangoproject.com/en/dev/topics/db/instrumentation/ + """ + + def __init__(self): + self.queries = [] + + # pylint: disable=too-many-arguments + def __call__(self, execute, sql, params, many, context): + current_query = {"sql": sql, "params": params, "many": many} + start = time.monotonic() + try: + result = execute(sql, params, many, context) + except Exception as err: # pylint: disable=broad-except + current_query["status"] = "error" + current_query["exception"] = err + raise + else: + current_query["status"] = "ok" + return result + finally: + duration = time.monotonic() - start + current_query["duration"] = duration + self.queries.append(current_query) + + +def raise_long_query_runtime(queries, threshold=0.0006): + """Raises an exception if any query took longer than the threshold""" + for query in queries: + if query["duration"] > threshold: + raise Exception( # pylint: disable=broad-exception-raised + "This looks like a slow query:", query["duration"], query["sql"] + ) diff --git a/bookwyrm/tests/views/books/test_book.py b/bookwyrm/tests/views/books/test_book.py index ee6e7d8b47..fa0a328a39 100644 --- a/bookwyrm/tests/views/books/test_book.py +++ b/bookwyrm/tests/views/books/test_book.py @@ -7,6 +7,7 @@ from django.contrib.auth.models import Group, Permission from django.contrib.contenttypes.models import ContentType from django.core.files.uploadedfile import SimpleUploadedFile +from django.db import connection from django.http import Http404 from django.template.response import TemplateResponse from django.test import TestCase @@ -16,8 +17,9 @@ from bookwyrm import forms, models, views from bookwyrm.activitypub import ActivitypubResponse from bookwyrm.tests.validate_html import validate_html +from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime - +# pylint: disable=invalid-name class BookViews(TestCase): """books books books""" @@ -68,9 +70,15 @@ def test_book_page(self): ) request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.books.books.is_api_request") as is_api: - is_api.return_value = False - result = view(request, self.book.id) + + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.books.books.is_api_request") as is_api: + is_api.return_value = False + result = view(request, self.book.id) + + raise_long_query_runtime(query_logger.queries) + self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) From b84ca3d03f1e9f6a95cae1446ee05a9c5a282aa2 Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Sat, 8 Jun 2024 19:21:39 -0700 Subject: [PATCH 2/8] Uses query duration tester in more places --- bookwyrm/tests/query_logger.py | 4 +-- bookwyrm/tests/views/books/test_book.py | 28 +++++++++++++------- bookwyrm/tests/views/landing/test_landing.py | 25 +++++++++++------ 3 files changed, 37 insertions(+), 20 deletions(-) diff --git a/bookwyrm/tests/query_logger.py b/bookwyrm/tests/query_logger.py index 6474ff41b2..e8ee7bdd6b 100644 --- a/bookwyrm/tests/query_logger.py +++ b/bookwyrm/tests/query_logger.py @@ -17,7 +17,7 @@ def __call__(self, execute, sql, params, many, context): start = time.monotonic() try: result = execute(sql, params, many, context) - except Exception as err: # pylint: disable=broad-except + except Exception as err: # pylint: disable=broad-except current_query["status"] = "error" current_query["exception"] = err raise @@ -34,6 +34,6 @@ def raise_long_query_runtime(queries, threshold=0.0006): """Raises an exception if any query took longer than the threshold""" for query in queries: if query["duration"] > threshold: - raise Exception( # pylint: disable=broad-exception-raised + raise Exception( # pylint: disable=broad-exception-raised "This looks like a slow query:", query["duration"], query["sql"] ) diff --git a/bookwyrm/tests/views/books/test_book.py b/bookwyrm/tests/views/books/test_book.py index fa0a328a39..c891208392 100644 --- a/bookwyrm/tests/views/books/test_book.py +++ b/bookwyrm/tests/views/books/test_book.py @@ -16,8 +16,8 @@ from bookwyrm import forms, models, views from bookwyrm.activitypub import ActivitypubResponse -from bookwyrm.tests.validate_html import validate_html from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime +from bookwyrm.tests.validate_html import validate_html # pylint: disable=invalid-name class BookViews(TestCase): @@ -117,26 +117,34 @@ def test_book_page_statuses(self, *_): request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.books.books.is_api_request") as is_api: - is_api.return_value = False - result = view(request, self.book.id, user_statuses="review") + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.books.books.is_api_request") as is_api: + is_api.return_value = False + result = view(request, self.book.id, user_statuses="review") + raise_long_query_runtime(query_logger.queries) + self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) self.assertEqual(result.context_data["statuses"].object_list[0], review) - with patch("bookwyrm.views.books.books.is_api_request") as is_api: - is_api.return_value = False - result = view(request, self.book.id, user_statuses="comment") + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.books.books.is_api_request") as is_api: + is_api.return_value = False + result = view(request, self.book.id, user_statuses="comment") + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) self.assertEqual(result.context_data["statuses"].object_list[0], comment) - with patch("bookwyrm.views.books.books.is_api_request") as is_api: - is_api.return_value = False - result = view(request, self.book.id, user_statuses="quotation") + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.books.books.is_api_request") as is_api: + is_api.return_value = False + result = view(request, self.book.id, user_statuses="quotation") + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) diff --git a/bookwyrm/tests/views/landing/test_landing.py b/bookwyrm/tests/views/landing/test_landing.py index c68c9cd532..240741cacf 100644 --- a/bookwyrm/tests/views/landing/test_landing.py +++ b/bookwyrm/tests/views/landing/test_landing.py @@ -1,6 +1,7 @@ """ test for app action functionality """ from unittest.mock import patch from django.contrib.auth.models import AnonymousUser +from django.db import connection from django.http import Http404 from django.template.response import TemplateResponse from django.test import TestCase @@ -8,9 +9,11 @@ from bookwyrm import models from bookwyrm import views +from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime from bookwyrm.tests.validate_html import validate_html +# pylint: disable=invalid-name class LandingViews(TestCase): """pages you land on without really trying""" @@ -39,7 +42,7 @@ def setUp(self): @patch("bookwyrm.suggested_users.SuggestedUsers.get_suggestions") def test_home_page(self, _): - """there are so many views, this just makes sure it LOADS""" + """home page for a logged in user""" view = views.Home.as_view() request = self.factory.get("") request.user = self.local_user @@ -54,6 +57,19 @@ def test_home_page(self, _): self.assertEqual(result.status_code, 200) validate_html(result.render()) + def test_landing(self): + """tests landing page for an anonymous user""" + view = views.Landing.as_view() + request = self.factory.get("") + + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + result = view(request) + raise_long_query_runtime(query_logger.queries) + + validate_html(result.render()) + self.assertIsInstance(result, TemplateResponse) + def test_about_page(self): """there are so many views, this just makes sure it LOADS""" view = views.about @@ -105,10 +121,3 @@ def test_impressum_page_on(self): self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) - - def test_landing(self): - """there are so many views, this just makes sure it LOADS""" - view = views.Landing.as_view() - request = self.factory.get("") - result = view(request) - self.assertIsInstance(result, TemplateResponse) From 9984e853e5ca6693b7f93d1abc901a6812d5e8a9 Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Sat, 8 Jun 2024 20:10:08 -0700 Subject: [PATCH 3/8] Adds test for query that creates bookwyrm export query --- bookwyrm/tests/models/test_bookwyrm_export_job.py | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/bookwyrm/tests/models/test_bookwyrm_export_job.py b/bookwyrm/tests/models/test_bookwyrm_export_job.py index 29a2a07c18..807a05d8f0 100644 --- a/bookwyrm/tests/models/test_bookwyrm_export_job.py +++ b/bookwyrm/tests/models/test_bookwyrm_export_job.py @@ -5,13 +5,16 @@ from unittest.mock import patch +from django.db import connection from django.utils import timezone from django.test import TestCase from bookwyrm import models +from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime from bookwyrm.utils.tar import BookwyrmTarFile +# pylint: disable=invalid-name class BookwyrmExportJob(TestCase): """testing user export functions""" @@ -159,6 +162,14 @@ def setUp(self): models.bookwyrm_export_job.create_export_json_task(job_id=self.job.id) self.job.refresh_from_db() + def test_create_export_job_query_time(self): + """test the creation of the job""" + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.models.bookwyrm_export_job.create_archive_task.delay"): + models.bookwyrm_export_job.create_export_json_task(job_id=self.job.id) + raise_long_query_runtime(query_logger.queries) + def test_add_book_to_user_export_job(self): """does AddBookToUserExportJob ...add the book to the export?""" self.assertIsNotNone(self.job.export_json["books"]) From ca822e1b832f941fa37f68fb55b375ef9f312954 Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Sat, 27 Jul 2024 08:41:50 -0700 Subject: [PATCH 4/8] Adds query logger to more tests --- bookwyrm/tests/views/test_author.py | 85 ++++++++++++++++++++--------- 1 file changed, 59 insertions(+), 26 deletions(-) diff --git a/bookwyrm/tests/views/test_author.py b/bookwyrm/tests/views/test_author.py index ed65fc30bb..5defe99712 100644 --- a/bookwyrm/tests/views/test_author.py +++ b/bookwyrm/tests/views/test_author.py @@ -4,15 +4,18 @@ from django.contrib.auth.models import AnonymousUser, Group, Permission from django.contrib.contenttypes.models import ContentType from django.core.exceptions import PermissionDenied +from django.db import connection from django.template.response import TemplateResponse from django.test import TestCase from django.test.client import RequestFactory from bookwyrm import forms, models, views from bookwyrm.activitypub import ActivitypubResponse +from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime from bookwyrm.tests.validate_html import validate_html +# pylint: disable=invalid-name class AuthorViews(TestCase): """author views""" @@ -61,9 +64,12 @@ def test_author_page(self): self.book.authors.add(author) request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.author.is_api_request") as is_api: - is_api.return_value = False - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.author.is_api_request") as is_api: + is_api.return_value = False + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) @@ -81,9 +87,12 @@ def test_author_page_edition_author(self): self.book.authors.add(author) request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.author.is_api_request") as is_api: - is_api.return_value = False - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.author.is_api_request") as is_api: + is_api.return_value = False + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) books = result.context_data["books"] self.assertEqual(books.object_list.count(), 1) @@ -97,9 +106,12 @@ def test_author_page_empty(self): author = models.Author.objects.create(name="Jessica") request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.author.is_api_request") as is_api: - is_api.return_value = False - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.author.is_api_request") as is_api: + is_api.return_value = False + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) @@ -110,9 +122,12 @@ def test_author_page_logged_out(self): author = models.Author.objects.create(name="Jessica") request = self.factory.get("") request.user = self.anonymous_user - with patch("bookwyrm.views.author.is_api_request") as is_api: - is_api.return_value = False - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.author.is_api_request") as is_api: + is_api.return_value = False + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) @@ -123,9 +138,12 @@ def test_author_page_api_response(self): author = models.Author.objects.create(name="Jessica") request = self.factory.get("") request.user = self.local_user - with patch("bookwyrm.views.author.is_api_request") as is_api: - is_api.return_value = True - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.views.author.is_api_request") as is_api: + is_api.return_value = True + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, ActivitypubResponse) self.assertEqual(result.status_code, 200) @@ -137,7 +155,10 @@ def test_edit_author_page(self): request.user = self.local_user request.user.is_superuser = True - result = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + result = view(request, author.id) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) @@ -153,8 +174,11 @@ def test_edit_author(self): request = self.factory.post("", form.data) request.user = self.local_user - with patch("bookwyrm.models.activitypub_mixin.broadcast_task.apply_async"): - view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch("bookwyrm.models.activitypub_mixin.broadcast_task.apply_async"): + view(request, author.id) + raise_long_query_runtime(query_logger.queries) author.refresh_from_db() self.assertEqual(author.name, "New Name") self.assertEqual(author.last_edited_by, self.local_user) @@ -169,8 +193,11 @@ def test_edit_author_non_editor(self): request = self.factory.post("", form.data) request.user = self.local_user - with self.assertRaises(PermissionDenied): - view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with self.assertRaises(PermissionDenied): + view(request, author.id) + raise_long_query_runtime(query_logger.queries) author.refresh_from_db() self.assertEqual(author.name, "Test Author") @@ -185,7 +212,10 @@ def test_edit_author_invalid_form(self): request = self.factory.post("", form.data) request.user = self.local_user - resp = view(request, author.id) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + resp = view(request, author.id) + raise_long_query_runtime(query_logger.queries) author.refresh_from_db() self.assertEqual(author.name, "Test Author") validate_html(resp.render()) @@ -208,8 +238,11 @@ def test_update_author_from_remote(self): request = self.factory.post("") request.user = self.local_user - with patch( - "bookwyrm.connectors.openlibrary.Connector.update_author_from_remote" - ) as mock: - views.update_author_from_remote(request, author.id, "openlibrary.org") - self.assertEqual(mock.call_count, 1) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + with patch( + "bookwyrm.connectors.openlibrary.Connector.update_author_from_remote" + ) as mock: + views.update_author_from_remote(request, author.id, "openlibrary.org") + self.assertEqual(mock.call_count, 1) + raise_long_query_runtime(query_logger.queries) From 26b6699b268434f4cf77a6d1a6bfb54cafb20371 Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Fri, 9 Aug 2024 13:39:06 -0700 Subject: [PATCH 5/8] Moves query logger duration into pytest.ini file --- bookwyrm/tests/query_logger.py | 7 ++++++- pytest.ini | 1 + 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/bookwyrm/tests/query_logger.py b/bookwyrm/tests/query_logger.py index e8ee7bdd6b..44bb6d015f 100644 --- a/bookwyrm/tests/query_logger.py +++ b/bookwyrm/tests/query_logger.py @@ -1,5 +1,10 @@ """ Log query runtimes for testing """ import time +from environs import Env + +env = Env() +env.read_env() +MAX_QUERY_DURATION = float(env("MAX_QUERY_DURATION")) class QueryLogger: @@ -30,7 +35,7 @@ def __call__(self, execute, sql, params, many, context): self.queries.append(current_query) -def raise_long_query_runtime(queries, threshold=0.0006): +def raise_long_query_runtime(queries, threshold=MAX_QUERY_DURATION): """Raises an exception if any query took longer than the threshold""" for query in queries: if query["duration"] > threshold: diff --git a/pytest.ini b/pytest.ini index b963fb316a..154fdee72c 100644 --- a/pytest.ini +++ b/pytest.ini @@ -28,3 +28,4 @@ env = EMAIL_HOST_PASSWORD = EMAIL_USE_TLS = true ENABLE_PREVIEW_IMAGES = false + MAX_QUERY_DURATION = 0.005 From dc72b5b9a00efd15839229cd82ab41557d9c4deb Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Fri, 9 Aug 2024 13:57:05 -0700 Subject: [PATCH 6/8] Adds query time logger to dashbaord views --- bookwyrm/tests/views/admin/test_dashboard.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/bookwyrm/tests/views/admin/test_dashboard.py b/bookwyrm/tests/views/admin/test_dashboard.py index 35fcb25a4d..05ba812107 100644 --- a/bookwyrm/tests/views/admin/test_dashboard.py +++ b/bookwyrm/tests/views/admin/test_dashboard.py @@ -2,12 +2,14 @@ from unittest.mock import patch from django.contrib.auth.models import Group +from django.db import connection from django.template.response import TemplateResponse from django.test import TestCase from django.test.client import RequestFactory from bookwyrm import models, views from bookwyrm.management.commands import initdb +from bookwyrm.tests.query_logger import QueryLogger, raise_long_query_runtime from bookwyrm.tests.validate_html import validate_html @@ -46,7 +48,10 @@ def test_dashboard(self): request = self.factory.get("") request.user = self.local_user - result = view(request) + query_logger = QueryLogger() + with connection.execute_wrapper(query_logger): + result = view(request) + raise_long_query_runtime(query_logger.queries) self.assertIsInstance(result, TemplateResponse) validate_html(result.render()) self.assertEqual(result.status_code, 200) From cf55a89816be82ecd19edc1d739801464600ebca Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Fri, 9 Aug 2024 13:58:20 -0700 Subject: [PATCH 7/8] Ups the max query time so that all tests pass --- pytest.ini | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/pytest.ini b/pytest.ini index 8116da1c09..6c53bdc958 100644 --- a/pytest.ini +++ b/pytest.ini @@ -25,4 +25,4 @@ env = EMAIL_HOST_PASSWORD = EMAIL_USE_TLS = true ENABLE_PREVIEW_IMAGES = false - MAX_QUERY_DURATION = 0.005 + MAX_QUERY_DURATION = 0.007 From 0ff2fe9d80b47fe3008fc94eb6f548c792f432ef Mon Sep 17 00:00:00 2001 From: Mouse Reeve Date: Fri, 9 Aug 2024 15:59:48 -0700 Subject: [PATCH 8/8] Adds 10k more books to book page test --- bookwyrm/tests/views/books/test_book.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/bookwyrm/tests/views/books/test_book.py b/bookwyrm/tests/views/books/test_book.py index c891208392..042d9fcf08 100644 --- a/bookwyrm/tests/views/books/test_book.py +++ b/bookwyrm/tests/views/books/test_book.py @@ -53,6 +53,8 @@ def setUpTestData(cls): remote_id="https://example.com/book/1", parent_work=cls.work, ) + for i in range(10000): + models.Edition.objects.create(title=i, parent_work=cls.work) models.SiteSettings.objects.create()