Thread: JSON down performacen when id:1

JSON down performacen when id:1

From

Render Comunicacion S.L.

Date:

16 December 2022, 16:30:42

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@render.es

657661974 · Denia 50, bajo izquierda · 46006 · Valencia

Re: JSON down performacen when id:1

From

Tom Lane

Date:

16 December 2022, 18:06:51

"Render Comunicacion S.L." <alex@render.es> writes:
> 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. ( ~
expectedtime) 

Your index is providing pretty awful performance:

>         ->  Bitmap Heap Scan on matrix  (cost=92.21..199.36 rows=27 width=1144) (actual time=415.708..8325.296
rows=11loops=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.462rows=155031 loops=1) 
>                     Index Cond: ((datos #> '{relations}'::text[]) @> '[{"section_id": "1", "section_tipo":
"numisdata3"}]'::jsonb)

I read that as 155K hits delivered by the index, of which only 11 were
real matches.  To make matters worse, with so many hits the bitmap was
allowed to become "lossy" (ie track some hits at page-level not
tuple-level) to conserve memory, so that the executor actually had to
check even more than 155K rows.

You need a better index.  It might be that switching to a jsonb_path_ops
index would be enough to fix it, or you might need to build an expression
index matched specifically to this type of query.  See

https://www.postgresql.org/docs/current/datatype-json.html#JSON-INDEXING

Also, if any of the terminology there doesn't make sense, read

https://www.postgresql.org/docs/current/indexes.html

            regards, tom lane

Re: JSON down performacen when id:1

From

"Render Comunicacion S.L."

Date:

16 December 2022, 20:01:47

Hi Tom

Thanks for your quick answer.

I did not mention that the index for all tables is:

CREATE INDEX IF NOT EXISTS matrix_relations_idx

ON public.matrix USING gin

((datos #> '{relations}') jsonb_path_ops) TABLESPACE pg_default;

And we try with and without jsonb_path_ops option with similar results.

My question is about, what is the difference between the first 3 searches and the > 4 search?

We don't know why in the first 3 cases seems that PostgreSQL doesn't use the index, and the result takes the same time with or without index, and the > 4, every number higher of 3, it works perfectly...

We are really desperate about this...

Thanks in avance.

Best
Alex
alex@render.es

657661974 · Denia 50, bajo izquierda · 46006 · Valencia

pastedGraphic.tiff

On 16 Dec 2022, at 16:06, Tom Lane <tgl@sss.pgh.pa.us> wrote:

"Render Comunicacion S.L." <alex@render.es> writes:
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)

Your index is providing pretty awful performance:

       -> 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)

I read that as 155K hits delivered by the index, of which only 11 were
real matches. To make matters worse, with so many hits the bitmap was
allowed to become "lossy" (ie track some hits at page-level not
tuple-level) to conserve memory, so that the executor actually had to
check even more than 155K rows.

You need a better index. It might be that switching to a jsonb_path_ops
index would be enough to fix it, or you might need to build an expression
index matched specifically to this type of query. See

https://www.postgresql.org/docs/current/datatype-json.html#JSON-INDEXING

Also, if any of the terminology there doesn't make sense, read

https://www.postgresql.org/docs/current/indexes.html

regards, tom lane

Attachment

pastedGraphic.tiff