Recentemente, descobri que a instância de banco de dados do meu aplicativo de produção atinge cerca de 100% da CPU e, quando observo as consultas travadas, vejo muitas consultas travadas que envolvem uma tabela que tem uma coluna contendo uma lista de ancestrais, e basicamente fazendo uma substring de expressão regular para encontrar o ID pai dessa coluna e, em seguida, executando um NOT IN
para excluir linhas que são pais ...
SELECT fp.*, admin_folders.id AS folder_id FROM folder_permissions fp RIGHT OUTER JOIN (
SELECT f.* FROM folders f WHERE f.deleted = FALSE AND ((SUBSTRING(f.ancestry FROM '([^/]*)$')::integer NOT IN (SELECT f2.id FROM folders f2 WHERE deleted = FALSE)) OR (f.ancestry IS NULL))
) admin_folders
ON admin_folders.id = fp.folder_id
AND fp.user_id = 12345 ORDER BY lower(admin_folders.name);
Inicialmente pensei que talvez a substring com o regex estivesse causando o problema, então tentei adicionar uma coluna ltree e alterá-la para ((ltree2text(subpath(f.path, -2, 1))::integer
... Isso pareceu torná-lo um pouco mais rápido em ambientes inferiores, mas novamente o banco de dados de produção trava indefinidamente quando esta consulta é feito.
O que é interessante para mim é que, nos ambientes inferiores, se eu fizer essa consulta com um ID de usuário que tenha mais de 100.000 registros de permissão de pasta, ela será instantânea.
----------------------------------------------------------------------------------------------------------------------------------
Sort (cost=24.49..24.50 rows=5 width=73) (actual time=4.286..4.289 rows=8 loops=1)
Sort Key: (lower((f.name)::text))
Sort Method: quicksort Memory: 25kB
-> Nested Loop Left Join (cost=10.22..24.43 rows=5 width=73) (actual time=3.810..3.997 rows=8 loops=1)
Join Filter: (f.id = fp.folder_id)
-> Seq Scan on folders f (cost=10.22..20.62 rows=5 width=520) (actual time=3.448..3.624 rows=8 loops=1)
Filter: ((NOT deleted) AND ((NOT (hashed SubPlan 1)) OR (ancestry IS NULL)))
Rows Removed by Filter: 14
SubPlan 1
-> Seq Scan on folders f2 (cost=0.00..10.20 rows=10 width=4) (actual time=0.008..0.018 rows=22 loops=1)
Filter: (NOT deleted)
-> Materialize (cost=0.00..3.72 rows=1 width=37) (actual time=0.015..0.015 rows=0 loops=8)
-> Seq Scan on folder_permissions fp (cost=0.00..3.71 rows=1 width=37) (actual time=0.120..0.120 rows=0 loops=1)
Filter: (user_id = 12345)
Rows Removed by Filter: 175
Planning Time: 2.346 ms
Execution Time: 5.266 ms
(17 rows)
No ambiente de produção, tentando com um usuário que tem apenas 8.000 registros de permissão de pasta, ele trava indefinidamente... Deixei o explicar analisar rodando por mais de 8 horas e nunca vejo a saída...
Os ambientes inferiores e superiores têm os mesmos índices e tentei reconstruí-los.
*** ATUALIZAR ***
Conforme solicitado, aqui está a explicação da máquina de pendurar:
=> explain SELECT fp.*, admin_folders.id AS folder_id FROM folder_permissions fp RIGHT OUTER JOIN (SELECT f.* FROM folders f WHERE f.deleted = FALSE AND ((SUBSTRING(f.ancestry FROM '([^/]*)$')::integer NOT IN (SELECT f2.id FROM folders f2 WHERE deleted = FALSE)) OR (f.ancestry IS NULL))) admin_folders ON admin_folders.id = fp.folder_id AND fp.user_id = 12345 ORDER BY lower(admin_folders.name);
QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------------------
Gather Merge (cost=332160509.79..332167328.27 rows=58440 width=73)
Workers Planned: 2
-> Sort (cost=332159509.77..332159582.82 rows=29220 width=73)
Sort Key: (lower((f.name)::text))
-> Merge Left Join (cost=17496.11..332157342.42 rows=29220 width=73)
Merge Cond: (f.id = fp.folder_id)
-> Parallel Index Scan using index_folder_id_on_undeleted_v2 on folders f (cost=0.42..332139670.56 rows=29220 width=20)
Filter: ((NOT (SubPlan 1)) OR (ancestry IS NULL))
SubPlan 1
-> Materialize (cost=0.00..11018.00 rows=140223 width=4)
-> Seq Scan on folders f2 (cost=0.00..9768.88 rows=140223 width=4)
Filter: (NOT deleted)
-> Sort (cost=17495.69..17507.71 rows=4807 width=37)
Sort Key: fp.folder_id
-> Bitmap Heap Scan on folder_permissions fp (cost=93.82..17201.72 rows=4807 width=37)
Recheck Cond: (user_id = 12345)
-> Bitmap Index Scan on index_folder_permissions_on_user_id (cost=0.00..92.62 rows=4807 width=0)
Index Cond: (user_id = 12345)
(18 rows)
E explique a análise na consulta SEM a parte NOT IN:
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=410.76..410.84 rows=33 width=73) (actual time=12.446..12.483 rows=43 loops=1)
Sort Key: (lower((f.name)::text))
Sort Method: quicksort Memory: 28kB
-> Nested Loop Left Join (cost=5.11..409.92 rows=33 width=73) (actual time=0.417..12.314 rows=43 loops=1)
-> Bitmap Heap Scan on folders f (cost=4.68..130.41 rows=33 width=20) (actual time=0.392..1.518 rows=43 loops=1)
Recheck Cond: ((ancestry IS NULL) AND (NOT deleted))
Heap Blocks: exact=43
-> Bitmap Index Scan on index_folders_on_ancestry_and_not_deleted (cost=0.00..4.67 rows=33 width=0) (actual time=0.220..0.221 rows=1620 loops=1)
Index Cond: (ancestry IS NULL)
-> Index Scan using index_folder_permissions_on_folder_id_and_user_id on folder_permissions fp (cost=0.44..8.46 rows=1 width=37) (actual time=0.246..0.246 rows=0 loops=43)
Index Cond: ((folder_id = f.id) AND (user_id = 12345))
Planning Time: 0.464 ms
Execution Time: 12.581 ms
(13 rows)
E a mesma coisa na máquina não suspensa:
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=556.42..556.53 rows=45 width=73) (actual time=0.685..0.726 rows=49 loops=1)
Sort Key: (lower((f.name)::text))
Sort Method: quicksort Memory: 29kB
-> Nested Loop Left Join (cost=5.20..555.19 rows=45 width=73) (actual time=0.045..0.589 rows=49 loops=1)
-> Bitmap Heap Scan on folders f (cost=4.77..174.15 rows=45 width=17) (actual time=0.025..0.178 rows=49 loops=1)
Recheck Cond: ((ancestry IS NULL) AND (NOT deleted))
Heap Blocks: exact=45
-> Bitmap Index Scan on index_folders_on_ancestry_and_not_deleted (cost=0.00..4.76 rows=45 width=0) (actual time=0.014..0.015 rows=51 loops=1)
Index Cond: (ancestry IS NULL)
-> Index Scan using index_folder_permissions_on_folder_id_and_user_id on folder_permissions fp (cost=0.43..8.46 rows=1 width=37) (actual time=0.004..0.005 rows=0 loops=49)
Index Cond: ((folder_id = f.id) AND (user_id = 12345))
Planning Time: 0.404 ms
Execution Time: 0.845 ms
(13 rows)
e por último, explique a parte da consulta que causa o travamento:
compass=> explain SELECT f.* FROM folders f WHERE f.deleted = FALSE AND ((SUBSTRING(f.ancestry FROM '([^/]*)$')::integer NOT IN (SELECT f2.id FROM folders f2 WHERE deleted = FALSE)) OR (f.ancestry IS NULL));
QUERY PLAN
------------------------------------------------------------------------------------------------------------
Gather (cost=3547.07..332130118.64 rows=70128 width=486)
Workers Planned: 2
-> Parallel Bitmap Heap Scan on folders f (cost=2547.07..332122105.84 rows=29220 width=486)
Recheck Cond: (NOT deleted)
Filter: ((NOT (SubPlan 1)) OR (ancestry IS NULL))
-> Bitmap Index Scan on index_folder_id_on_undeleted_v2 (cost=0.00..2529.53 rows=140223 width=0)
SubPlan 1
-> Materialize (cost=0.00..11018.00 rows=140223 width=4)
-> Seq Scan on folders f2 (cost=0.00..9768.88 rows=140223 width=4)
Filter: (NOT deleted)
(10 rows)
A subconsulta na junção direita:
é melhor ser escrito como
Acho difícil recomendar índices; talvez se eu ver
EXPLAIN (ANALYZE, BUFFERS)
a subconsulta aprimorada.A diferença devastadora é entre
NOT (hashed SubPlan 1)
eNOT (SubPlan 1)
que é impulsionada pela diferença na estimativa entre 10 linhas (reais: 22) e 140.223 linhas (reais: desconhecidas). A mudança ocorre porque seu work_mem não é grande o suficiente para acomodar uma tabela hash com a contagem esperada de 140223 valores.Isso sugere que seu work_mem é bastante baixo, pois não é necessária muita memória para acomodar uma tabela hash desse tamanho. Portanto, embora possa haver outras maneiras de resolver isso, uma coisa simples seria aumentar work_mem, o que provavelmente deveria ser feito de qualquer maneira se você estiver executando consultas como esta.
Além disso, você provavelmente deveria recriar seu ambiente de teste, já que 22 vs 140223 é uma enorme diferença na estimativa de contagem de linhas. É provável que haja todos os tipos de diferenças de planos entre os sistemas.