JSON down performacen when id:1

From: Render Comunicacion S(dot)L(dot) <alex(at)render(dot)es>
To: pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: JSON down performacen when id:1
Date: 2022-12-16 13:30:42
Message-ID: B9DBE179-BF2D-4D41-A94D-CC9520E2EEBA@render.es
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hello to everyone

I'm new here, and I hope that my question is on the correct mail-list.

We use PostgreSQL to store JSON-B in different tables, all tables have the same schema and all tables are indexed with GIN index for the JSON data.

We use two properties of the JSON to locate data:

{
"section_id":"1",
"section_tipo":"numisdata3"
}

The issue:
When we search our locator with section_id: 1 (or any number < 4), PostgreSQL takes around 40000, 5000, 8000ms or more.
When we search our locator with section_id: 4 (or any other bigger number), PostgreSQL takes around 100 ms. ( ~ expected time)

Next queries are done in a database with +/- 1 million of rows in total, and we tested in PostgreSQL 13,14 and 15 with similar results.

_____________________________________________

The query for section_id: 1 (13 rows)

EXPLAIN ANALYZE SELECT section_tipo, section_id, datos
FROM "matrix"
WHERE (
datos#>'{relations}' @> '[{"section_id":"1","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_activities"
WHERE (
datos#>'{relations}' @> '[{"section_id":"1","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_hierarchy"
WHERE (
datos#>'{relations}' @> '[{"section_id":"1","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_list"
WHERE (
datos#>'{relations}' @> '[{"section_id":"1","section_tipo":"numisdata3"}]'::jsonb)
ORDER BY section_tipo, section_id ASC
LIMIT ALL;

QUERY PLAN
Sort (cost=8984.49..8991.16 rows=2669 width=1357) (actual time=8752.794..8752.797 rows=13 loops=1)
Sort Key: matrix.section_tipo, matrix.section_id
Sort Method: quicksort Memory: 47kB
-> Append (cost=92.21..8832.59 rows=2669 width=1357) (actual time=415.709..8741.565 rows=13 loops=1)
-> Bitmap Heap Scan on matrix (cost=92.21..199.36 rows=27 width=1144) (actual time=415.708..8325.296 rows=11 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 272037
Heap Blocks: exact=34164 lossy=33104
-> Bitmap Index Scan on matrix_relations_idx (cost=0.00..92.20 rows=27 width=0) (actual time=61.462..61.462 rows=155031 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
-> Seq Scan on matrix_activities (cost=0.00..0.00 rows=1 width=68) (actual time=0.012..0.012 rows=0 loops=1)
Filter: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_hierarchy (cost=52.26..8492.67 rows=2614 width=1362) (actual time=269.624..414.954 rows=2 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 5043
Heap Blocks: exact=3034
-> Bitmap Index Scan on matrix_hierarchy_relations_idx (cost=0.00..51.61 rows=2614 width=0) (actual time=9.529..9.529 rows=5049 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_list (cost=12.21..100.53 rows=27 width=1161) (actual time=1.260..1.260 rows=0 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Index Scan on matrix_list_relations_idx (cost=0.00..12.21 rows=27 width=0) (actual time=1.258..1.258 rows=0 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo": "numisdata3"}]'::jsonb)
Planning Time: 33.625 ms
Execution Time: 8753.461 ms

_____________________________________________

The query for section_id: 2 (18 rows)

EXPLAIN ANALYZE SELECT section_tipo, section_id, datos
FROM "matrix"
WHERE (
datos#>'{relations}' @> '[{"section_id":"2","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_activities"
WHERE (
datos#>'{relations}' @> '[{"section_id":"2","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_hierarchy"
WHERE (
datos#>'{relations}' @> '[{"section_id":"2","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_list"
WHERE (
datos#>'{relations}' @> '[{"section_id":"2","section_tipo":"numisdata3"}]'::jsonb)
ORDER BY section_tipo, section_id ASC
LIMIT ALL;

Sort (cost=8984.49..8991.16 rows=2669 width=1357) (actual time=5236.090..5236.097 rows=18 loops=1)
Sort Key: matrix.section_tipo, matrix.section_id
Sort Method: quicksort Memory: 57kB
-> Append (cost=92.21..8832.59 rows=2669 width=1357) (actual time=200.244..5235.964 rows=18 loops=1)
-> Bitmap Heap Scan on matrix (cost=92.21..199.36 rows=27 width=1144) (actual time=200.244..5188.015 rows=16 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 270935
Heap Blocks: exact=33885 lossy=33106
-> Bitmap Index Scan on matrix_relations_idx (cost=0.00..92.20 rows=27 width=0) (actual time=51.763..51.764 rows=153659 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
-> Seq Scan on matrix_activities (cost=0.00..0.00 rows=1 width=68) (actual time=0.022..0.022 rows=0 loops=1)
Filter: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_hierarchy (cost=52.26..8492.67 rows=2614 width=1362) (actual time=5.112..47.171 rows=2 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 2479
Heap Blocks: exact=1805
-> Bitmap Index Scan on matrix_hierarchy_relations_idx (cost=0.00..51.61 rows=2614 width=0) (actual time=4.834..4.834 rows=2484 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_list (cost=12.21..100.53 rows=27 width=1161) (actual time=0.738..0.738 rows=0 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Index Scan on matrix_list_relations_idx (cost=0.00..12.21 rows=27 width=0) (actual time=0.735..0.735 rows=0 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "2", "section_tipo": "numisdata3"}]'::jsonb)
Planning Time: 30.869 ms
Execution Time: 5236.796 ms

_____________________________________________

The query for section_id: 3 (7 rows)

EXPLAIN ANALYZE SELECT section_tipo, section_id, datos
FROM "matrix"
WHERE (
datos#>'{relations}' @> '[{"section_id":"3","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_activities"
WHERE (
datos#>'{relations}' @> '[{"section_id":"3","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_hierarchy"
WHERE (
datos#>'{relations}' @> '[{"section_id":"3","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_list"
WHERE (
datos#>'{relations}' @> '[{"section_id":"3","section_tipo":"numisdata3"}]'::jsonb)
ORDER BY section_tipo, section_id ASC
LIMIT ALL;

Sort (cost=8984.49..8991.16 rows=2669 width=1357) (actual time=1796.808..1796.813 rows=7 loops=1)
Sort Key: matrix.section_tipo, matrix.section_id
Sort Method: quicksort Memory: 36kB
-> Append (cost=92.21..8832.59 rows=2669 width=1357) (actual time=114.715..1796.731 rows=7 loops=1)
-> Bitmap Heap Scan on matrix (cost=92.21..199.36 rows=27 width=1144) (actual time=114.714..1403.005 rows=6 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 63200
Heap Blocks: exact=39788
-> Bitmap Index Scan on matrix_relations_idx (cost=0.00..92.20 rows=27 width=0) (actual time=52.239..52.239 rows=63248 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
-> Seq Scan on matrix_activities (cost=0.00..0.00 rows=1 width=68) (actual time=0.018..0.018 rows=0 loops=1)
Filter: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_hierarchy (cost=52.26..8492.67 rows=2614 width=1362) (actual time=329.263..392.708 rows=1 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 4925
Heap Blocks: exact=2996
-> Bitmap Index Scan on matrix_hierarchy_relations_idx (cost=0.00..51.61 rows=2614 width=0) (actual time=6.059..6.059 rows=4930 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_list (cost=12.21..100.53 rows=27 width=1161) (actual time=0.988..0.988 rows=0 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Index Scan on matrix_list_relations_idx (cost=0.00..12.21 rows=27 width=0) (actual time=0.985..0.985 rows=0 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "3", "section_tipo": "numisdata3"}]'::jsonb)
Planning Time: 4.339 ms
Execution Time: 1797.240 ms

_____________________________________________

The query for section_id: 4 (6 rows)

EXPLAIN ANALYZE SELECT section_tipo, section_id, datos
FROM "matrix"
WHERE (
datos#>'{relations}' @> '[{"section_id":"4","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_activities"
WHERE (
datos#>'{relations}' @> '[{"section_id":"4","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_hierarchy"
WHERE (
datos#>'{relations}' @> '[{"section_id":"4","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_list"
WHERE (
datos#>'{relations}' @> '[{"section_id":"4","section_tipo":"numisdata3"}]'::jsonb)
ORDER BY section_tipo, section_id ASC
LIMIT ALL;

QUERY PLAN
Sort (cost=8984.49..8991.16 rows=2669 width=1357) (actual time=25.171..25.174 rows=6 loops=1)
Sort Key: matrix.section_tipo, matrix.section_id
Sort Method: quicksort Memory: 34kB
-> Append (cost=92.21..8832.59 rows=2669 width=1357) (actual time=6.227..25.112 rows=6 loops=1)
-> Bitmap Heap Scan on matrix (cost=92.21..199.36 rows=27 width=1144) (actual time=6.227..24.955 rows=4 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 1758
Heap Blocks: exact=1469
-> Bitmap Index Scan on matrix_relations_idx (cost=0.00..92.20 rows=27 width=0) (actual time=3.139..3.139 rows=1765 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
-> Seq Scan on matrix_activities (cost=0.00..0.00 rows=1 width=68) (actual time=0.010..0.010 rows=0 loops=1)
Filter: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_hierarchy (cost=52.26..8492.67 rows=2614 width=1362) (actual time=0.101..0.126 rows=2 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 1
Heap Blocks: exact=3
-> Bitmap Index Scan on matrix_hierarchy_relations_idx (cost=0.00..51.61 rows=2614 width=0) (actual time=0.088..0.088 rows=3 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_list (cost=12.21..100.53 rows=27 width=1161) (actual time=0.015..0.015 rows=0 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Index Scan on matrix_list_relations_idx (cost=0.00..12.21 rows=27 width=0) (actual time=0.015..0.015 rows=0 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "4", "section_tipo": "numisdata3"}]'::jsonb)
Planning Time: 3.579 ms
Execution Time: 25.278 ms

_____________________________________________

The query for section_id: 5 (24 rows)

EXPLAIN ANALYZE SELECT section_tipo, section_id, datos
FROM "matrix"
WHERE (
datos#>'{relations}' @> '[{"section_id":"5","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_activities"
WHERE (
datos#>'{relations}' @> '[{"section_id":"5","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_hierarchy"
WHERE (
datos#>'{relations}' @> '[{"section_id":"5","section_tipo":"numisdata3"}]'::jsonb)
UNION ALL
SELECT section_tipo, section_id, datos
FROM "matrix_list"
WHERE (
datos#>'{relations}' @> '[{"section_id":"5","section_tipo":"numisdata3"}]'::jsonb)
ORDER BY section_tipo, section_id ASC
LIMIT ALL;

QUERY PLAN
Sort (cost=8984.49..8991.16 rows=2669 width=1357) (actual time=111.243..111.249 rows=28 loops=1)
Sort Key: matrix.section_tipo, matrix.section_id
Sort Method: quicksort Memory: 69kB
-> Append (cost=92.21..8832.59 rows=2669 width=1357) (actual time=13.804..111.086 rows=28 loops=1)
-> Bitmap Heap Scan on matrix (cost=92.21..199.36 rows=27 width=1144) (actual time=13.803..108.578 rows=26 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 5967
Heap Blocks: exact=4691
-> Bitmap Index Scan on matrix_relations_idx (cost=0.00..92.20 rows=27 width=0) (actual time=11.815..11.815 rows=6000 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
-> Seq Scan on matrix_activities (cost=0.00..0.00 rows=1 width=68) (actual time=0.011..0.011 rows=0 loops=1)
Filter: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_hierarchy (cost=52.26..8492.67 rows=2614 width=1362) (actual time=2.034..2.052 rows=2 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
Rows Removed by Index Recheck: 1
Heap Blocks: exact=3
-> Bitmap Index Scan on matrix_hierarchy_relations_idx (cost=0.00..51.61 rows=2614 width=0) (actual time=1.987..1.987 rows=4 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Heap Scan on matrix_list (cost=12.21..100.53 rows=27 width=1161) (actual time=0.426..0.426 rows=0 loops=1)
Recheck Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
-> Bitmap Index Scan on matrix_list_relations_idx (cost=0.00..12.21 rows=27 width=0) (actual time=0.418..0.418 rows=0 loops=1)
Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "5", "section_tipo": "numisdata3"}]'::jsonb)
Planning Time: 4.328 ms
Execution Time: 111.514 ms

_____________________________________________

We have checked the index and it's ok, we did vacuum, vacuum analyze...

We can understand that the first 3 searches for section_id didn't use the index... But... how can we fix it?

Thanks!

Best
Alex
alex(at)render(dot)es

657661974 · Denia 50, bajo izquierda · 46006 · Valencia

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2022-12-16 15:06:51 Re: JSON down performacen when id:1
Previous Message James Pang (chaolpan) 2022-12-15 12:19:54 RE: DML sql execution time slow down PGv14 compared with PGv13