I am working on a Web application that renders a food menu in one view. The menu is modelled as one big tree, which contains nodes like services (breakfast, lunch, dinner), courses (starter, main, dessert), and products.
We store the nodes in a table called menu_items.
CREATE TABLE "menu_items" (
"id" uuid DEFAULT gen_random_uuid() PRIMARY KEY,
"created_time" TIMESTAMP(6) WITH TIME ZONE DEFAULT NOW() NOT NULL,
"menu_id" uuid NOT NULL REFERENCES "menus"("id") ON DELETE CASCADE,
"type_id" text NOT NULL REFERENCES "menu_item_types"("id"), -- super-type, e.g. "service"
"parent_id" uuid REFERENCES "menu_items"("id") ON DELETE CASCADE,
"attributes" jsonb
);
Menu Items have sub-types, which are inserted into a separate table at the same time as the super-type.
CREATE TABLE "menu_product_version_items" (
"id" uuid PRIMARY KEY REFERENCES "menu_items"("id") ON DELETE CASCADE,
"product_id" uuid REFERENCES "products"("id") -- This can be NULL
);
One more thing
A Menu Product Item references a product from products, and products have versions in the product_versions. Product Versions also have a relationship with other important data like product_nutrients (e.g. protein, fat, and sugar).
Problem
As the products table has grown 10k+, the Web application response times have drastically increased to an unusable level. I discovered this is because of the database query that retrieves the menu items.
(I apologise in advance.)
EXPLAIN (ANALYZE, BUFFERS) SELECT
mi.id,
mi.created_time,
mi.type_id,
mi.parent_id,
mi.attributes,
msi.service_id,
mdi.dish_id,
mci.course_id,
mdui.duration,
pv.product_version
FROM menu_items AS mi
LEFT JOIN menu_service_items AS msi ON msi.id = mi."id"
LEFT JOIN menu_dish_items AS mdi ON mdi.id = mi."id"
LEFT JOIN menu_course_items AS mci ON mci.id = mi."id"
LEFT JOIN menu_duration_items AS mdui ON mdui.id = mi."id"
LEFT JOIN menu_product_version_items AS mpvi ON mpvi.id = mi."id"
LEFT JOIN (
SELECT
"pv"."product_id" AS "id",
"pv".created_time,
json_build_object(
'id', "p"."id",
'code', "p"."code",
'createdTime', "pv"."created_time",
'name', "pv"."name",
'ingredients', "pv"."ingredients",
'quantity', CASE
WHEN "pv"."quantity" IS NOT NULL THEN json_build_object(
'value', "pv"."quantity",
'unit', json_build_object(
'symbol', u.symbol
)
)
ELSE NULL
END,
'servingCount', "pv"."serving_count",
'nutrients', COALESCE("nutrients", '[]'::JSONB)
) AS product_version
FROM products AS p
LEFT JOIN "product_versions" AS "pv" ON "pv"."product_id" = "p"."id"
LEFT JOIN "units" AS "u" ON "u"."id" = "pv"."quantity_unit_id"
LEFT JOIN (
SELECT
pn.product_id AS "id",
jsonb_agg(
json_build_object(
'id', n.id,
'name', n.name,
'quantity', json_build_object(
'value', pn.quantity,
'unit', json_build_object(
'symbol', u.symbol
)
)
) ORDER BY n."name" ASC
) AS nutrients
FROM product_nutrients AS pn
LEFT JOIN nutrients AS n ON n."id" = pn.nutrient_id
LEFT JOIN units AS u ON u."id" = pn.quantity_unit_id
GROUP BY pn.product_id
) n ON pv."product_id" = n."id"
) pv ON pv."id" = mpvi."product_id" AND
pv.created_time = (
SELECT MAX(pv2.created_time)
FROM product_versions AS pv2
WHERE
pv2.product_id = mpvi."product_id" AND
pv2.created_time <= mi."created_time"
)
WHERE mi.menu_id = 'uuid'
ORDER BY mi.created_time
LIMIT 5000;
Output
Limit (cost=16503.85..16505.00 rows=457 width=142) (actual time=403.426..403.473 rows=458 loops=1)
Buffers: shared hit=11561, temp read=1227 written=1227
-> Sort (cost=16503.85..16505.00 rows=457 width=142) (actual time=403.425..403.448 rows=458 loops=1)
Sort Key: mi.created_time
Sort Method: quicksort Memory: 101kB
Buffers: shared hit=11561, temp read=1227 written=1227
-> Hash Left Join (cost=12655.30..16483.66 rows=457 width=142) (actual time=397.157..403.327 rows=458 loops=1)
Hash Cond: ((mpvi.product_id = pv.product_id) AND ((SubPlan 2) = pv.created_time))
Buffers: shared hit=11558, temp read=1227 written=1227
-> Hash Left Join (cost=22.85..46.67 rows=457 width=126) (actual time=0.440..0.758 rows=458 loops=1)
Hash Cond: (mi.id = mpvi.id)
Buffers: shared hit=17
-> Hash Left Join (cost=21.76..44.37 rows=457 width=110) (actual time=0.419..0.691 rows=458 loops=1)
Hash Cond: (mi.id = mdui.id)
Buffers: shared hit=16
-> Hash Left Join (cost=20.22..41.61 rows=457 width=94) (actual time=0.374..0.592 rows=458 loops=1)
Hash Cond: (mi.id = mci.id)
Buffers: shared hit=15
-> Hash Left Join (cost=12.53..32.71 rows=457 width=88) (actual time=0.248..0.409 rows=458 loops=1)
Hash Cond: (mi.id = mdi.id)
Buffers: shared hit=13
-> Hash Left Join (cost=6.75..25.72 rows=457 width=77) (actual time=0.153..0.255 rows=458 loops=1)
Hash Cond: (mi.id = msi.id)
Buffers: shared hit=11
-> Seq Scan on menu_items mi (cost=0.00..17.76 rows=457 width=71) (actual time=0.041..0.083 rows=458 loops=1)
Filter: (menu_id = '834cbb51-5962-4c1e-ae63-a3276edf6421'::uuid)
Rows Removed by Filter: 244
Buffers: shared hit=9
-> Hash (cost=4.11..4.11 rows=211 width=22) (actual time=0.101..0.101 rows=211 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 20kB
Buffers: shared hit=2
-> Seq Scan on menu_service_items msi (cost=0.00..4.11 rows=211 width=22) (actual time=0.007..0.039 rows=211 loops=1)
Buffers: shared hit=2
-> Hash (cost=3.68..3.68 rows=168 width=27) (actual time=0.081..0.081 rows=168 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 18kB
Buffers: shared hit=2
-> Seq Scan on menu_dish_items mdi (cost=0.00..3.68 rows=168 width=27) (actual time=0.008..0.034 rows=168 loops=1)
Buffers: shared hit=2
-> Hash (cost=4.53..4.53 rows=253 width=22) (actual time=0.116..0.116 rows=253 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 22kB
Buffers: shared hit=2
-> Seq Scan on menu_course_items mci (cost=0.00..4.53 rows=253 width=22) (actual time=0.006..0.045 rows=253 loops=1)
Buffers: shared hit=2
-> Hash (cost=1.24..1.24 rows=24 width=32) (actual time=0.031..0.032 rows=56 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 12kB
Buffers: shared hit=1
-> Seq Scan on menu_duration_items mdui (cost=0.00..1.24 rows=24 width=32) (actual time=0.005..0.013 rows=56 loops=1)
Buffers: shared hit=1
-> Hash (cost=1.04..1.04 rows=4 width=32) (actual time=0.010..0.011 rows=14 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 9kB
Buffers: shared hit=1
-> Seq Scan on menu_product_version_items mpvi (cost=0.00..1.04 rows=4 width=32) (actual time=0.003..0.005 rows=14 loops=1)
Buffers: shared hit=1
-> Hash (cost=12546.19..12546.19 rows=5751 width=56) (actual time=396.596..396.599 rows=5751 loops=1)
Buckets: 8192 (originally 8192) Batches: 4 (originally 1) Memory Usage: 4035kB
Buffers: shared hit=11516, temp written=974
-> Nested Loop Left Join (cost=584.62..12546.19 rows=5751 width=56) (actual time=7.811..382.611 rows=5751 loops=1)
Buffers: shared hit=11516
-> Hash Join (cost=584.48..12368.12 rows=5751 width=399) (actual time=7.783..324.530 rows=5751 loops=1)
Hash Cond: (pv.product_id = p.id)
Buffers: shared hit=11514
-> Hash Right Join (cost=407.11..12175.63 rows=5751 width=377) (actual time=5.070..320.096 rows=5751 loops=1)
Hash Cond: (pn.product_id = pv.product_id)
Buffers: shared hit=11466
-> GroupAggregate (cost=0.71..11628.75 rows=5619 width=48) (actual time=0.137..312.101 rows=5737 loops=1)
Group Key: pn.product_id
Buffers: shared hit=11189
-> Nested Loop Left Join (cost=0.71..10574.01 rows=78760 width=38) (actual time=0.031..57.917 rows=78760 loops=1)
Buffers: shared hit=11186
-> Nested Loop Left Join (cost=0.57..8730.70 rows=78760 width=42) (actual time=0.026..36.978 rows=78760 loops=1)
Buffers: shared hit=11176
-> Index Scan using product_nutrients_pkey on product_nutrients pn (cost=0.42..6789.49 rows=78760 width=33) (actual time=0.009..12.120 rows=78760 loops=1)
Buffers: shared hit=11126
-> Memoize (cost=0.15..0.17 rows=1 width=14) (actual time=0.000..0.000 rows=1 loops=78760)
Cache Key: pn.nutrient_id
Cache Mode: logical
Hits: 78735 Misses: 25 Evictions: 0 Overflows: 0 Memory Usage: 3kB
Buffers: shared hit=50
-> Index Scan using nutrients_pkey on nutrients n (cost=0.14..0.16 rows=1 width=14) (actual time=0.001..0.001 rows=1 loops=25)
Index Cond: (id = pn.nutrient_id)
Buffers: shared hit=50
-> Memoize (cost=0.14..0.16 rows=1 width=12) (actual time=0.000..0.000 rows=1 loops=78760)
Cache Key: pn.quantity_unit_id
Cache Mode: logical
Hits: 78755 Misses: 5 Evictions: 0 Overflows: 0 Memory Usage: 1kB
Buffers: shared hit=10
-> Index Scan using units_pkey on units u_1 (cost=0.13..0.15 rows=1 width=12) (actual time=0.001..0.001 rows=1 loops=5)
Index Cond: (id = pn.quantity_unit_id)
Buffers: shared hit=10
-> Hash (cost=334.51..334.51 rows=5751 width=345) (actual time=4.900..4.901 rows=5751 loops=1)
Buckets: 8192 Batches: 1 Memory Usage: 2184kB
Buffers: shared hit=277
-> Seq Scan on product_versions pv (cost=0.00..334.51 rows=5751 width=345) (actual time=0.008..1.355 rows=5751 loops=1)
Buffers: shared hit=277
-> Hash (cost=105.50..105.50 rows=5750 width=22) (actual time=2.679..2.680 rows=5750 loops=1)
Buckets: 8192 Batches: 1 Memory Usage: 369kB
Buffers: shared hit=48
-> Seq Scan on products p (cost=0.00..105.50 rows=5750 width=22) (actual time=0.006..0.829 rows=5750 loops=1)
Buffers: shared hit=48
-> Memoize (cost=0.14..0.16 rows=1 width=12) (actual time=0.000..0.000 rows=1 loops=5751)
Cache Key: pv.quantity_unit_id
Cache Mode: logical
Hits: 5749 Misses: 2 Evictions: 0 Overflows: 0 Memory Usage: 1kB
Buffers: shared hit=2
-> Index Scan using units_pkey on units u (cost=0.13..0.15 rows=1 width=12) (actual time=0.004..0.004 rows=0 loops=2)
Index Cond: (id = pv.quantity_unit_id)
Buffers: shared hit=2
SubPlan 2
-> Result (cost=8.30..8.31 rows=1 width=8) (actual time=0.000..0.000 rows=1 loops=464)
Buffers: shared hit=25
InitPlan 1 (returns $2)
-> Limit (cost=0.28..8.30 rows=1 width=8) (actual time=0.000..0.000 rows=0 loops=464)
Buffers: shared hit=25
-> Index Only Scan Backward using product_versions_pkey on product_versions pv2 (cost=0.28..8.30 rows=1 width=8) (actual time=0.000..0.000 rows=0 loops=464)
Index Cond: ((product_id = mpvi.product_id) AND (created_time IS NOT NULL) AND (created_time <= mi.created_time))
Heap Fetches: 0
Buffers: shared hit=25
Planning:
Buffers: shared hit=519
Planning Time: 8.594 ms
Execution Time: 403.816 ms
Using https://explain.dalibo.com/plan/6583987cagb520ce#plan/node/28 to visualise the above plan, I can see that the product_nutrients aggregation is taking an especially long time. I imagine there's a lot of room for optimisation, but I have focussed on this following advice in "what to focus on" from https://www.cybertec-postgresql.com/en/how-to-interpret-postgresql-explain-analyze-output/.
How can I improve the performance of the aggregation (and other factors in the above query)?
LEFTon anyJOINyou see.n ON pv."product_id" = n."id"looks problematic in your query: PostgreSQL can't push predicates down to that subquery, you need to rewrite in usingLATERAL