8000 Increase in queries number · Issue #288 · django-ordered-model/django-ordered-model · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

Increase in queries number #288

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
Closed
lauxley opened this issue Mar 15, 2023 · 6 comments
Closed

Increase in queries number #288

lauxley opened this issue Mar 15, 2023 · 6 comments

Comments

@lauxley
Copy link
lauxley commented Mar 15, 2023

After upgrading django-ordered-model from 3.6 to 3.7.2, some of my tests started failing because the number of queries went up.
Example with one test:

$ pip freeze | grep ordered
django-ordered-model==3.6

$ python manage.py test users.tests.TeamTestCase.test_leave_group
Found 1 test(s).
Creating test database for alias 'default'...
System check identified no issues (0 silenced).
.
----------------------------------------------------------------------
Ran 1 test in 0.280s

OK
Destroying test database for alias 'default'...

$ pip install -U django-ordered-model
Requirement already satisfied: django-ordered-model in ./env/lib/python3.9/site-packages (3.6)
Collecting django-ordered-model
  Using cached django_ordered_model-3.7.2-py3-none-any.whl (20 kB)
Installing collected packages: django-ordered-model
  Attempting uninstall: django-ordered-model
    Found existing installation: django-ordered-model 3.6
    Uninstalling django-ordered-model-3.6:
      Successfully uninstalled django-ordered-model-3.6
Successfully installed django-ordered-model-3.7.2

$ python manage.py test users.tests.TeamTestCase.test_leave_group
Found 1 test(s).
Creating test database for alias 'default'...
System check identified no issues (0 silenced).
F
======================================================================
FAIL: test_leave_group (users.tests.TeamTestCase)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/robin/Projects/escriptorium/app/apps/users/tests.py", line 210, in test_leave_group
    response = self.client.post(url)
  File "/home/robin/Projects/escriptorium/app/env/lib/python3.9/site-packages/django/test/testcases.py", line 100, in __exit__
    self.test_case.assertEqual(
AssertionError: 5 != 4 : 5 queries executed, 4 expected
Captured queries were:
1. SELECT "django_session"."session_key", "django_session"."session_data", "django_session"."expire_date" FROM "django_session" WHERE ("django_session"."expire_date" > '2023-03-15T15:07:30.907726+00:00'::timestamptz AND "django_session"."session_key" = '0e03xotem80bxuaew0yy20cnxm6j9cbz') LIMIT 21
2. SELECT "users_user"."id", "users_user"."password", "users_user"."last_login", "users_user"."is_superuser", "users_user"."username", "users_user"."first_name", "users_user"."last_name", "users_user"."is_staff", "users_user"."is_active", "users_user"."date_joined", "users_user"."email", "users_user"."quota_disk_storage", "users_user"."quota_cpu", "users_user"."quota_gpu" FROM "users_user" WHERE "users_user"."id" = 2 LIMIT 21
3. SELECT "auth_group"."id", "auth_group"."name" FROM "auth_group" WHERE "auth_group"."id" = 1 LIMIT 21
4. SELECT "users_user_groups"."id", "users_user_groups"."user_id", "users_user_groups"."group_id" FROM "users_user_groups" WHERE ("users_user_groups"."group_id" = 1 AND "users_user_groups"."user_id" IN (2))
5. DELETE FROM "users_user_groups" WHERE "users_user_groups"."id" IN (2)

----------------------------------------------------------------------
Ran 1 test in 0.278s

FAILED (failures=1)
Destroying test database for alias 'default'..

Nothing else changed between both run of the test beside the django-ordered-model version.
Here is the queries run with django-ordered-model 3.6:

1. SELECT "django_session"."session_key", "django_session"."session_data", "django_session"."expire_date" FROM "django_session" WHERE ("django_session"."expire_date" > '2023-03-15T15:17:43.626631+00:00'::timestamptz AND "django_session"."session_key" = 'w2nbd56xmaz6ngnu57q2pz80vlhd894u') LIMIT 21
2. SELECT "users_user"."id", "users_user"."password", "users_user"."last_login", "users_user"."is_superuser", "users_user"."username", "users_user"."first_name", "users_user"."last_name", "users_user"."is_staff", "users_user"."is_active", "users_user"."date_joined", "users_user"."email", "users_user"."quota_disk_storage", "users_user"."quota_cpu", "users_user"."quota_gpu" FROM "users_user" WHERE "users_user"."id" = 2 LIMIT 21
3. SELECT "auth_group"."id", "auth_group"."name" FROM "auth_group" WHERE "auth_group"."id" = 1 LIMIT 21
4. DELETE FROM "users_user_groups" WHERE ("users_user_groups"."group_id" = 1 AND "users_user_groups"."user_id" IN (2))

The 3 first queries are the same in both cases but 4th and 5th are different.
The user model is NOT ordered, it is an AbstractUser and does not make any use of any of OrderedModel feature, nor does the Group model which is the base django Group model with nothing added.

from django.contrib.auth.models import AbstractUser

class User(AbstractUser):
   ...
@shuckc
Copy link
Member
shuckc commented Mar 15, 2023

Quite a large project - am I missing anything obvious trying to reproduce it below?
Perhaps the new on-delete signal handler is the cause. I'd put a breakpoint there.

$ git clone https://gitlab.com/scripta/escriptorium.git
$ cd escriptorium
$ python -m venv venv
$ . ven/bin/activate
$ cd app
$ pip install -r requirements-dev.txt -r requirements.txt
   .....zzzzzzZZZZZZZ
$ pip install --upgrade django-ordered-model
$ python manage.py test users.tests.TeamTestCase.test_leave_group
scikit-learn version 1.2.2 is not supported. Minimum required version: 0.17. Maximum required version: 1.1.2. Disabling scikit-learn conversion API.
Traceback (most recent call last):
  File "/home/chris/repos/django/escriptorium/app/manage.py", line 15, in <module>
    execute_from_command_line(sys.argv)
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/django/core/management/__init__.py", line 446, in execute_from_command_line
    utility.execute()
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/django/core/management/__init__.py", line 420, in execute
    django.setup()
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/django/__init__.py", line 24, in setup
    apps.populate(settings.INSTALLED_APPS)
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/django/apps/registry.py", line 116, in populate
    app_config.import_models()
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/django/apps/config.py", line 304, in import_models
    self.models_module = import_module(models_module_name)
  File "/usr/lib/python3.10/importlib/__init__.py", line 126, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
  File "<frozen importlib._bootstrap>", line 1050, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1027, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1006, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 688, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 883, in exec_module
  File "<frozen importlib._bootstrap>", line 241, in _call_with_frames_removed
  File "/home/chris/repos/django/escriptorium/app/apps/core/models.py", line 37, in <module>
    from kraken.kraken import SEGMENTATION_DEFAULT_MODEL
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/kraken/kraken.py", line 35, in <module>
    from kraken.lib.progress import KrakenProgressBar, KrakenDownloadProgressBar
  File "/home/chris/repos/django/escriptorium/venv/lib/python3.10/site-packages/kraken/lib/progress.py", line 22, in <module>
    from pytorch_lightning.callbacks.progress.base import ProgressBarBase
ModuleNotFoundError: No module named 'pytorch_lightning.callbacks.progress.base'

@shuckc
Copy link
Member
shuckc commented Mar 15, 2023

OK I can run your test case, will take a look this evening. $ pip install pytorch-lightning==1.9.4 and some postgress faff did the trick.

@shuckc
Copy link
Member
shuckc commented Mar 15, 2023 •
edited
Loading

From a bisect, 3.6 passes, 3.7.0 passes, 3.7.1 and above fails

If I remove our post_delete signal handler registration, the test passes. It turns out that Django has a model deletion concept called a "fast delete" which allows it to optimise the deletion process if nobody is listening. Our signal handler trips this causing the slowpath with the extra query.

What we can probably do is move the point of registration to make it restricted to subclasses of OrderedModelBase, and register the handler once for each Model, rather than a single global handler (that does type inspection) with these unanticipated side effects. It might be that delete() on an OrderedModel becomes more expensive due to this slow path, but that seems the lessor evil than the correctness issue leaving ordering gaps that the signal addresses.

I will work up a PR to optimise this. Also FYI @ibaguio as you might be sensitive to this.

@shuckc shuckc mentioned this issue Mar 15, 2023
Merged
shuckc added a commit that referenced this issue Mar 15, 2023
@shuckc
rework cascaded/queryset delete detection to avoid global signal list…
7470e88 
…ener

Restrict signal handler 'senders' to subclasses of `OrderedModelBase` to avoid query count regression due to `Collector.can_fast_delete` logic in `models/deletion.py
fixes #288
@shuckc
Copy link
Member
shuckc commented Mar 16, 2023

Fixed in 3.7.3

@shuckc shuckc closed this as completed Mar 16, 2023
shuckc added a commit that referenced this issue Mar 16, 2023
@shuckc
rework cascaded/queryset delete detection to avoid global signal list…
743cb6d 
…ener

Restrict signal handler 'senders' to subclasses of `OrderedModelBase` to avoid query count regression due to `Collector.can_fast_delete` logic in `models/deletion.py
fixes #288
@shuckc
Copy link
Member
shuckc commented Mar 16, 2023

There is a query-count failure in FAIL: test_move (apps.api.tests.PartViewSetTestCase) too, not 'obviously' wrong but let me know if you think it's a regression.

@shuckc
Copy link
Member
shuckc commented Mar 16, 2023

On closer review FAIL: test_move (apps.api.tests.PartViewSetTestCase) needs 7 queries under 3.6, reduced to 6 queries under 3.7.1, this is a result of the optimisation to store lookup owrt values by FK_id.

You will need to patch the test if you unpin your deps as query 4 is eliminated from the test:

1. SELECT "django_session"."session_key", "django_session"."session_data", "django_session"."expire_date" FROM "django_session" WHERE ("django_session"."expire_date" > '2023-03-16T11:34:38.133323+00:00'::timestamptz AND "django_session"."session_key" = 'b9j9w55avrnuy2rub3wqu96antsv48td') LIMIT 21
2. SELECT "users_user"."id", "users_user"."password", "users_user"."last_login", "users_user"."is_superuser", "users_user"."username", "users_user"."first_name", "users_user"."last_name", "users_user"."is_staff", "users_user"."is_active", "users_user"."date_joined", "users_user"."email", "users_user"."quota_disk_storage", "users_user"."quota_cpu", "users_user"."quota_gpu" FROM "users_user" WHERE "users_user"."id" = 1 LIMIT 21
3. SELECT "core_documentpart"."id", "core_documentpart"."order", "core_documentpart"."name", "core_documentpart"."image", "core_documentpart"."original_filename", "core_documentpart"."image_file_size", "core_documentpart"."source", "core_documentpart"."bw_backend", "core_documentpart"."bw_image", "core_documentpart"."typology_id", "core_documentpart"."document_id", "core_documentpart"."comments", "core_documentpart"."created_at", "core_documentpart"."updated_at", "core_documentpart"."max_avg_confidence", "core_documentpart"."workflow_state", "core_documentpart"."transcription_progress" FROM "core_documentpart" WHERE ("core_documentpart"."document_id" = 1 AND "core_documentpart"."id" = 2) LIMIT 21
4. SELECT "core_document"."id", "core_document"."name", "core_document"."owner_id", "core_document"."workflow_state", "core_document"."main_script_id", "core_document"."read_direction", "core_document"."line_offset", "core_document"."typology_id", "core_document"."show_confidence_viz", "core_document"."created_at", "core_document"."updated_at", "core_document"."project_id" FROM "core_document" WHERE "core_document"."id" = 1 LIMIT 21
5. UPDATE "core_documentpart" SET "order" = ("core_documentpart"."order" + 1) WHERE ("core_documentpart"."document_id" = 1 AND "core_documentpart"."order" < 1 AND "core_documentpart"."order" >= 0)
6. UPDATE "core_documentpart" SET "order" = 0, "name" = '', "image" = 'documents/1/default_b3oBMak.png', "original_filename" = '', "image_file_size" = 35150, "source" = '', "bw_backend" = 'kraken', "bw_image" = '', "typology_id" = NULL, "document_id" = 1, "comments" = NULL, "created_at" = '2023-03-16T11:34:37.999505+00:00'::timestamptz, "updated_at" = '2023-03-16T11:34:38.145728+00:00'::timestamptz, "max_avg_confidence" = NULL, "workflow_state" = 0, "transcription_progress" = 0 WHERE "core_documentpart"."id" = 2
7. SELECT COUNT(*) AS "__count" FROM "core_line" WHERE "core_line"."document_part_id" = 2

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@lauxley @shuckc
0