Estou executando uma instrução select em uma tabela postgresql (em uma instância RDS) para somar valores em 2 mil linhas. A instrução select tem cerca de 100 parâmetros (principalmente países diferentes que queremos somar).
Quando executo essa consulta uma vez em meu aplicativo, ela será executada em aproximadamente 500 ms. No entanto, quando eu o executo várias vezes seguidas, a latência da consulta aumenta repentinamente de 10 a 20 vezes , para aproximadamente 5 a 10 segundos após 8 ou 9 execuções. (Essas medições são do lado do servidor dos logs RDS onde eu habilitei log_min_duration_statement).
O que poderia causar esse salto no tempo de execução? - Eu esperaria que a consulta fosse mais lenta na execução inicial, mas estou surpreso ao ver a latência aumentar após várias execuções consecutivas.
Algumas observações importantes:
- Pool de conexões : o pool de conexões exato não parece importar. O problema persiste quer eu use HikariCP ou C3P0
- Conexão única : esse problema não acontece se eu configurar meu pool de conexões para ter apenas uma única conexão (portanto, a lógica do aplicativo não é a culpada)
- PSQL : Esse problema também não acontece se eu comparar a consulta consequentemente usando
psqlpara executá-la. - Parâmetros de consulta : quando reduzo a quantidade de parâmetros de consulta para aproximadamente 60, não vejo nenhum problema. Somente quando procuro mais de 90 territórios é que me deparo com esse comportamento.
- Redefinição do pool : quando eu reinicio meu aplicativo (e, portanto, redefino o pool de conexões), as consultas voltam a ser rápidas (0,5s) por mais 8 a 9 consultas antes de ficarem lentas novamente (5s).
Tentei procurar os suspeitos do costume, como otimização do RDS IOPS Burst, carga do banco de dados e consumo de memória, conexões disponíveis, mas nada parece suspeito nesse aspecto.
Também me certifiquei de que o índice que a consulta está usando e as linhas retornadas da tabela sejam armazenadas em cache.
A consulta que estou executando tem o seguinte formato. Trunquei alguns dos 90 IDs de países:
SELECT d.primary_title_no,
SUM(d.cume) AS lifetime
FROM schema.my_data AS d
WHERE d.currency = 'USD'
AND d.date >= '2020-01-01'::date + (7 * (d.week - 1))
AND d.date < '2021-01-01'::date + (7 * (d.week - 1))
AND d.is_lifetime = TRUE
AND d.ter_id IN ('AE','AM', ... (100 odd values) ...,'WA','ZA')
GROUP BY d.primary_title_no
ORDER BY lifetime DESC
LIMIT 250;
É importante ressaltar que esse problema só acontece quando a consulta tem mais de 90 IDs de países. Posso executá-lo em 50 países sem problemas.
Para referência, aqui está o resultado de explain analyzeuma consulta com um tempo de execução rápido:
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| QUERY PLAN |
|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| Limit (cost=1218692.98..1218693.23 rows=100 width=12) (actual time=369.146..369.167 rows=100 loops=1) |
| -> Sort (cost=1218692.98..1218697.34 rows=1742 width=12) (actual time=369.145..369.154 rows=100 loops=1) |
| Sort Key: (sum(cume)) DESC |
| Sort Method: top-N heapsort Memory: 33kB |
| -> GroupAggregate (cost=1218595.34..1218626.41 rows=1742 width=12) (actual time=366.250..368.653 rows=1959 loops=1) |
| Group Key: primary_title_no |
| -> Sort (cost=1218595.34..1218599.89 rows=1820 width=12) (actual time=366.240..366.844 rows=5739 loops=1) |
| Sort Key: primary_title_no |
| Sort Method: quicksort Memory: 462kB |
| -> Index Scan using idx_dailies_currency_ter_id_primary_title_no_lifetime on dailies d (cost=0.43..1218496.79 rows=1820 width=12) (actual time=1.093..364.406 rows=5739 loops=1) |
| Index Cond: (((currency)::text = 'USD'::text) AND ((ter_id)::text = ANY ('{AE,AM,AR,AT,AU,AZ,BA,BE,BG,BH,BO,BR,BY,CH,CL,CN,CO,CR,CU,CZ,DE,DK,DO,EC,EE,EG,ES,FI,FR,GE,GR,GT,HK,HN,HR,HU,IL,IN,IQ,IS,IT,JP,KG,KR,KW,KZ,LB,LT,LU,LV,MD,MX,MY,MZ,NI,NL,NO,NZ,OM,PA,PE,PH,PL,PT,PY,QA,RO,RS,RU,SA,SE,SG,SI,SK,SV,TH,TJ,TM,TR,TT,TW,UK,UP,UY,UZ,WA,ZA}'::text[]))) |
| Filter: (((date - (7 * (week - 1))) >= '2020-01-01'::date) AND ((date - (7 * (week - 1))) < '2020-06-01'::date)) |
| Rows Removed by Filter: 314494 |
| Planning Time: 0.613 ms |
| Execution Time: 369.213 ms |
+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
Para um caso em que a consulta é executada lentamente, a explain analyzesaída é a mesma, mas 20 vezes o cálculo é gasto na Index Scanetapa mais interna.
Se alguém tiver alguma indicação de como posso solucionar esse problema, serei todo ouvidos.
Depois de analisar mais o problema com os parâmetros, encontrei a seguinte pergunta sobre stackoverflow sugerindo que:
Na documentação do Postgresql, plan_cache_mode está documentado da seguinte forma:
Quando executei a seguinte instrução dentro de uma transação com minha instrução select, o problema foi resolvido:
Atualização : acho que o problema ocorre em conjunto com a
work_memconfiguração de 4mb. Minha hipótese é que o plano genérico ocupa um pouco mais de memória, causando muitas trocas. Aumentar esse limite para 16 MB também resolve o problema: