2020-09-11 - Friday

DONE Write performance tests for [[id:2d69ab28-c16e-4736-b59f-ef6e1cc89aa2][ENG-12262]]

CLOSED: Mon Sep 14, 202009:47 SCHEDULED: Mon Sep 14, 2020

- Note taken on Mon Sep 14, 202012:52

Had a very productive day of building a test harness for performance testing this view with a lot of different parameters. My favorite result so far:

AssertionError: It took (17.495874404907227s) time to run the code. This is longer than the expected (0.6s).

Turns out when you cram a company full of 500 groups each with 2 queues of 20 questions each and another 20 active questions in one group this endpoint kind of dies a a slow heat death. I can control the degradation by adjusting the number of groups with questions. Simply cranking up the number of queues and questions does not cause the endpoint to fail as dramatically.

This maps well to the investigation into the query here:

#+BEGIN_SRC sql

SELECT "ff_question"."id", "ff_question"."delete_ts", "ff_question"."question_frequency", "ff_question"."frequency_params", "ff_question"."is_active", "ff_question"."company_id", "ff_question"."group_id", "ff_question"."user_id", "ff_question"."display_order", "ff_question"."create_ts", "ff_question"."update_ts", "ff_question"."creator_id", "ff_question"."updater_id", "ff_question"."question_text", "ff_question"."permanent_id", "ff_question"."question_type", "ff_question"."extra_json", "ff_question"."question_queue_id", "ff_question"."is_optional", "ff_question"."is_example", "ff_question"."context_text"

FROM "ff_question" WHERE ("ff_question"."delete_ts" IS NULL

AND NOT ("ff_question"."is_example" = true)

AND "ff_question"."company_id" = 14526

AND "ff_question"."group_id" IS NOT NULL

AND "ff_question"."is_active" = true

AND "ff_question"."question_queue_id" IS NULL)

#+END_SRC

Company ID 14526 is what’s causing all the drama here at the moment. Most companies do not have the same proportion of questions to groups and in those cases the slow views are generally occurring when the CompanyStruct is not found in cache (speeding up the building of CompanyStruct is not our problem right now). It’s worth noting that this company has 488active questions not in queues and 576 groups.

The query plan for the above query is:

#+BEGIN_SRC sql

Bitmap Heap Scan on ff_question (cost=4736.47..6695.85 rows=171 width=264) (actual time=161.955..163.103 rows=488 loops=1)

Recheck Cond: ((company_id = 14526) AND (group_id IS NOT NULL))

Filter: ((delete_ts IS NULL) AND (NOT is_example) AND is_active AND (question_queue_id IS NULL))

Rows Removed by Filter: 519

Heap Blocks: exact=727

-> BitmapAnd (cost=4736.47..4736.47 rows=539 width=0) (actual time=161.573..161.573 rows=0 loops=1)

-> Bitmap Index Scan on ff_question_company_id (cost=0.00..99.00 rows=4077 width=0) (actual time=17.127..17.127 rows=4111 loops=1)

Index Cond: (company_id = 14526)

-> Bitmap Index Scan on ff_question_group_id (cost=0.00..4637.12 rows=139293 width=0) (actual time=144.239..144.239 rows=143642 loops=1)

Index Cond: (group_id IS NOT NULL)

Planning Time: 8.170 ms

Execution Time: 167.536 ms

#+END_SRC

Which shows the index scan on ff_question_group_id is responsible for 144ms of actual time of our 167ms execution time.

The number of queries in this view is a constants 15, no matter how many queues, questions or groups a company has. This makes sense given the code in the view. The problem here does not appear to be an N(1) query explosion, but rather simply counting a lot of data every time the endpoint is hit.

The problem here, is that there’s not a lot of low hanging fruit. I’ve tried manipulating a few of the queries to reduce the number or complexity of the lookup. I’m still trying to come up with the best way to improve the results of my tests, which I’ll push up to a branch later this evening.

DONE [[id:7b5c0db6-16c7-447c-bd45-ace0f5ae1cdc][Friday Nature Hike]]

CLOSED: Mon Sep 14, 202009:47 SCHEDULED: Fri Sep 11, 2020

ID: d1c707ab-f690-11ea-b22a-e86a64ecc701