Tenho uma pergunta relacionada a um incidente que aconteceu em um de nossos bancos de dados Postgres.
Temos um serviço backend que monitora a atividade do usuário em algum tipo de evento online. O serviço utiliza o Postgres 12 como banco de dados, e para esse tipo de evento existe uma tabela (chamarei user_eventno restante da pergunta) onde os dados são mantidos. A tabela tinha cerca de 3.500 transações por segundo, principalmente atualizações (das quais quase todas eram atualizações HOT - isso pode ser uma parte importante).
Aqui está um gráfico separado para tuplas inseridas e excluídas (as excluídas são 0), pois não é visível na foto acima:
O número de tuplas ativas aumentou assim:
O uso da tabela começou em aproximadamente 11 e estava indo bem durante o dia, mas por volta das 18h o tamanho da tabela passou de aproximadamente 3 GB para> 80 GB em 2 horas. Isso fez com que o disco quase atingisse sua capacidade total, então tivemos que desabilitar o evento em andamento e fazer um vácuo completo, o que reduziu o tamanho da tabela de >80GB para ~3GB.
Aqui está o tamanho da tabela com estimativas de inchaço:
* calculamos o inchaço exibido no segundo gráfico com esta consulta
Os índices das tabelas não cresceram tanto:
Naquele momento (por volta das 20h30 - 21h), suspeitamos que o problema era o autovacuum e que precisava ser mais agressivo, então configuramos o tempo de soneca de 30s (o padrão é 1 min) e definimos para 0,005 e para 0 (os últimos autovacuum_vacuum_scale_factor2 autovacuum_vacuum_cost_delayparâmetros definimos apenas para a tabela crítica). Antes dessas mudanças, o autovacuum era executado uma vez a cada 60s antes das 18h e depois das 18h uma vez a cada 2min (devido ao crescimento da tabela).
Talvez uma informação importante seja que durante todo o evento, a grande maioria dos checkpoints foram solicitados (não cronometrados) com frequência de uma vez a cada 3-4 minutos:
Depois disso, o problema não se repetiu, mas ainda não conseguimos explicar por que e como aconteceu esse grande aumento no tamanho da tabela. Após uma inspeção detalhada, o autovacuum (e a autoanalyse) funcionou o tempo todo na mesa (confirmamos isso em métricas e logs).
Para lhe dar mais contexto, notamos uma mudança na dinâmica dos buffers quando a tabela começou a aumentar rapidamente (por volta das 18h):
Alguém tem uma ideia do que/onde procurar para explicar isso? Se precisar de mais informações, posso fornecê-las.
Dados adicionais: o esquema da tabela user_event é este:
# \d user_event;
Table "public.user_event"
Column | Type | Collation | Nullable | Default
----------------------------------+--------------------------+-----------+----------+---------
id | uuid | | not null |
event_id | text | | not null |
user_id | bigint | | not null |
server_id | integer | | not null |
state | text | | not null |
generator_type | text | | |
timestamp_when_claimable | timestamp with time zone | | not null |
claimeditems | jsonb | | not null |
timestamp_when_energy_full | timestamp with time zone | | not null |
overflow_energy | integer | | not null |
timestamp_when_energy_cost_reset | timestamp with time zone | | not null |
grid | jsonb | | not null |
refill_count | integer | | not null |
Indexes:
"user_event_pkey" PRIMARY KEY, btree (id)
"idx_event_id" btree (event_id)
"idx_event_id_state" btree (event_id, state)
"idx_login_id" btree (login_id)
"idx_login_id_event_id" btree (login_id, event_id)
A versão do Postgres é 12, com os parâmetros mais importantes:
- buffers_compartilhados: '6GB'
- manutenção_work_mem: 1 GB
- max_wal_size: 10 GB
- min_wal_size: 1 GB
- checkpoint_timeout: '10min'
- efetivo_cache_size: "58 GB"
- log_autovacuum_min_duration: 0
- autovacuum_vacuum_scale_factor: 0,02
- autovacuum_analyze_scale_factor: 0,01
Os recursos da VM são:
- 16 CPUs
- 64 GB de RAM
- Disco SSD de 250 GB
It is hard to know what your charts are actually showing. n_tup_hot_upd, for example, is a permanently increasing value, it only goes down when the system crashes or the stats gets reset. Yet your chart does not show it this way, so it must be plotting some kind of difference between consecutive snapshots. But in that case, is it also showing all the other lines on the same basis?
The important thing is not the percentage which were HOT, but the raw number which were not HOT. Your first chart doesn't really accentuate this aspect, but if you squint at it you can kind of see a gap opening up between the two lines right when the problem started occurring.
So the likely answer is that something was holding open a snapshot, which prevented HOT tuples from being pruned. Once the pages are full of unpruned HOT tuples, new versions need to go on new pages, defeating HOT. Updates on tuples put into those new pages would then qualify for HOT again, until those new pages again become full. So HOT never fully shuts off, its effectiveness just decays.
The non-HOT updates will trigger more vacuums to occur, but the vacuums can't actually do anything useful, because the same snapshot which defeats HOT update also defeats vacuuming.
As principais coisas que manteriam um instantâneo aberto por um longo tempo seriam uma consulta de execução muito longa ou uma transação em um nível de isolamento maior que READ COMMITTED que ficou ociosa na transação. Eles são fáceis de ver em pg_stat_activity enquanto ocorrem (query_start, xact_start, state), mas podem ser difíceis de determinar após o fato.