O commit que derrubava o pod

"Serviço do e-commerce e do financeiro estão ficando off quando temos requisições de pedidos novos."

Foi assim que o problema chegou. Em homologação, os dois serviços reiniciavam quando entravam pedidos novos, e a última task que eu tinha entregado mexia exatamente nesse caminho.

A suspeita óbvia era o meu código. Ela estava certa pela metade, o que não chega a ser absolvição: uma das quedas era minha, a outra já existia antes, e as duas passavam pelo mesmo health check de 1 segundo.

O que a task fazia

O sistema é dividido em microsserviços Quarkus, cada um com o próprio banco Postgres. O cliente nasce no serviço de cadastro, que publica a pessoa num tópico Kafka. Financeiro, vendas e estoque consomem esse tópico e gravam a sua cópia.

O e-commerce recebe pedidos de marketplaces e transforma cada um num pedido de venda no serviço de vendas. Quando o comprador era novo, o pedido chegava ao vendas antes de o cliente existir lá.

A task resolvia isso com uma confirmação: cada serviço avisa o cadastro quando gravou a pessoa, o cadastro anota numa tabela de acompanhamento e, quando todos confirmaram, publica um evento de replicação completa. Até lá, o pedido fica parado em AGUARDANDO_REPLICACAO.

No papel é simples. Na prática, cada seta é uma mensagem assíncrona seguida de um commit em outro banco, e cada uma delas pode chegar antes, depois ou duas vezes.

Mortos pelo kubelet

Antes de abrir código, fui ver como os pods morriam. O kubectl get pods mostrava 4 restarts no e-commerce e 6 no financeiro. O describe dos dois dizia a mesma coisa: exit code 137, Reason: Error, nada de OOM.

Nos eventos do financeiro, Liveness probe failed ... statuscode: 503 apareceu 29 vezes em 87 minutos, e Killing ... failed liveness probe, 6 vezes. Ninguém estava travando a JVM nem estourando memória. O Kubernetes olhava para o pod, achava que ele estava doente e resolvia do jeito dele.

Os probes dos dois serviços no cluster:

livenessProbe:
  httpGet:
    path: /api/status
  timeoutSeconds: 1
readinessProbe:
  httpGet:
    path: /api/status
  timeoutSeconds: 1

Nesses serviços, /api/status é a raiz do SmallRye Health, e a raiz agrega tudo: os checks de liveness, de readiness e de startup. Entram ali o checks de conexão com o banco e o estado de cada canal Kafka. Com 1 segundo de timeout, basta o banco demorar para o pod morrer.

Aqui veio a primeira pista falsa. O k8s/deploy.yml do repositório tinha timeout de 5 segundos, então por um tempo eu achei que estava lendo a configuração errada. Não estava.

Os pipelines só rodam kubectl set image: trocam a imagem e mais nada. O manifesto do repositório nunca é aplicado, e a configuração real vive no cluster, ajustada à mão em algum momento. O deploy.yml do repositório documenta um cluster que não existe.

Causa 1: o commit fora do try/catch

O log do container anterior do financeiro (kubectl logs --previous) cobria só os últimos 70 segundos de vida dele. Pouco, mas o bastante para o laudo:

11:11:41.571  Confirmação de replicação de cliente publicada com sucesso
              logo antes, no mesmo trecho:
              ARJUNA016053: Could not commit transaction
              Caused by: java.sql.SQLException: Enlisted connection used without active transaction
11:11:41.912  Reporting health down status
              SmallRye Reactive Messaging - liveness check: DOWN
              PessoaConsumer#incoming: [KO] - ARJUNA016053: Could not commit transaction.
11:11:42      Liveness probe failed: statuscode 503   (5 vezes até 11:12:22)
11:12:52      container morto, exit 137

Todos os outros checks estavam UP, inclusive o do banco. Só um canal tinha morrido: o consumer de pessoas, justamente onde a minha task tinha acrescentado o envio da confirmação. Era a metade da suspeita que acertou.

@Incoming("pessoa")
@Transactional(Transactional.TxType.REQUIRES_NEW)
@Retry(delay = 15, delayUnit = ChronoUnit.SECONDS)
public CompletionStage<Void> incoming(KafkaRecord<String, PessoaDTO> message) {
    return consume(dlq, message, record -> {
        PessoaDTO pessoa = record.getValue();
        boolean jaExistia = pessoaService.findByID(pessoa.getIdPessoa()).isPresent();
        pessoaService.save(pessoa);
 
        if (!jaExistia) {
            notificarClienteReplicado.execute(pessoa.getIdPessoa());
        }
    });
}

O consume mora numa classe base que os consumers do serviço estendem:

public CompletionStage<Void> consume(DLQTopicProperties dlq,
                                     KafkaRecord<String, T> message,
                                     Consumer<KafkaRecordDTO<T>> consumer) {
    try {
        consumer.accept(new KafkaRecordDTO<>(message));
        return message.ack();
    } catch (Exception e) {
        return message.nack(e, metadataDaDlq(dlq));
    }
}

Lendo os dois juntos, o problema aparece. O try/catch existe para que nenhum erro derrube o canal: qualquer exceção vira nack e a mensagem vai para a DLQ. Só que o @Transactional está do lado de fora, no incoming.

Como o método retorna CompletionStage, o Quarkus só faz o commit quando esse stage termina, depois que o consume já retornou e a mensagem já recebeu ack. Se o commit falha, o erro sai do incoming sem nenhum try/catch em volta e sem mensagem para mandar à DLQ.

O SmallRye marca o canal como KO, o check de liveness vai para DOWN, e só um restart traz o consumer de volta.

Por que o commit falhava eu sei só em parte. O que o log mostra: a confirmação sai de forma assíncrona, pelo Emitter, e o log dela aparece na kafka-producer-network-thread; em seguida o commit falha dizendo que a conexão está alistada sem transação ativa.

O que eu não provei é o caminho exato que deixa o commit fora do contexto da transação. Também vi essa sequência uma vez só, no sexto restart. Os outros cinco já tinham saído dos logs.

Para a correção isso não importava muito. A transação não precisava estar no @Incoming: o PessoaService.save já tem a dele. Quando ele retorna, o dado está commitado e a confirmação pode sair.

@Blocking
@Incoming("pessoa")
public CompletionStage<Void> incoming(KafkaRecord<String, PessoaDTO> message) {
    return consume(dlq, message, record -> {
        PessoaDTO pessoa = record.getValue();
        pessoaService.save(pessoa);                              // commit acontece aqui dentro
        notificarClienteReplicado.execute(pessoa.getIdPessoa()); // só depois do commit
    });
}

Agora qualquer falha, no save ou no envio, acontece dentro do try/catch e vai para a DLQ. O @Blocking manda a execução para uma worker thread, já que o método faz I/O de banco.

E o if (!jaExistia) saiu: uma pessoa que já existia no financeiro nunca confirmava, e o pedido dela ficava esperando para sempre. Esse era um dos bugs funcionais da task, e eu só vi porque estava relendo o método por outro motivo. Bug achado de carona.

O incômodo maior veio depois. Procurei o mesmo padrão, @Transactional num @Incoming que retorna CompletionStage, e ele aparece em 34 consumers de 5 serviços. Qualquer falha de commit em qualquer um deles derruba o canal e reinicia o pod.

Esses eu não corrigi: o lugar certo é a classe base, não 34 PRs com o mesmo diff.

Causa 2: duas conexões presas esperando HTTP

No e-commerce não havia canal KO. O container anterior viveu das 10:20:44 às 10:24:13 e morreu no meio de uma rajada de callbacks do integrador de marketplaces, que avisa por HTTP cada pedido novo ou alterado.

Somando o tempo dos 402 callbacks que estavam nos logs, deu 6.269 segundos. Só 15% disso foi em chamadas externas. Os outros 85% foram esperando conexão do banco.

O caminho de um callback:

POST /callback/marketplace
  → EventoService.save                       transação A: conexão 1
    → postInsert
      → EnviarEventoParaTarefas              @Transactional(REQUIRES_NEW): conexão 2
        → POST no serviço de tarefas         até 28 s durante a rajada

Cada callback segura duas conexões durante uma chamada HTTP que, na rajada, levou até 28 segundos. As conexões acabam, os callbacks seguintes recebem Acquisition timeout e respondem com código HTTP 500, o integrador, prestativo, reenvia, e a carga aumenta.

Sem conexão livre, o check de banco do /api/status passa de 1 segundo, e o kubelet faz o resto.

O REQUIRES_NEW ainda tinha um bug funcional: dentro da transação nova, o método busca o evento que a transação A ainda não commitou, não encontra, e o id da tarefa nunca é gravado.

Aqui eu errei a primeira conclusão, e errei por escrito. A métrica agroal_max_used_count do container mostrava 3, e eu afirmei no relatório que o pool de homologação era pequeno demais e que bastava aumentar o max-size.

Fui conferir no configmap e não havia nada lá: homologação roda com o perfil prod, que define max-size: 10. O pool nunca encheu: estava com 3 de 10 e levando a culpa.

E a mensagem de erro, lida com mais calma, dizia Acquisition timeout while waiting for new connection. O pool não estava esperando uma conexão ser devolvida, estava falhando ao abrir uma nova.

O Postgres de homologação é compartilhado entre os serviços. O pg_stat_activity mostrou max_connections de 191 e cerca de 100 conexões abertas com o sistema parado, 23 delas do Debezium.

Sobram duas hipóteses: a soma dos pools de todos os serviços bateu no limite do banco durante a rajada, ou abrir conexão ficou lento porque a instância estava sem crédito de CPU.

As métricas do RDS daquele intervalo decidem, e eu ainda não olhei. Até lá, aumentar o pool do e-commerce pode piorar tudo, se o gargalo for o banco.

O que transformava lentidão em restart

As duas causas são diferentes, mas o desfecho era o mesmo porque o health check não diferenciava "estou lento" de "estou quebrado".

Dos serviços no cluster, só o cadastro já usava o caminho certo: liveness em /api/status/live, com 2 segundos, e readiness em /api/status/ready, com 3. O check de banco é de readiness. Com essa separação, um banco lento tira o pod do balanceamento em vez de matá-lo.

Isso teria salvo o e-commerce, mas não o financeiro. Canal Kafka morto é check de liveness no SmallRye, e ali o restart é justamente o que faz o consumer voltar. Separar os probes evita matar quem está só lento. Não conserta quem está quebrado.

Tinha mais um caminho para o restart, que dessa vez não disparou. Com a estratégia de commit throttled, o conector Kafka do SmallRye considera o consumer travado se um registro fica mais de unprocessed-record-max-age sem terminar, e o padrão é 60 segundos.

Passou disso, o canal fica DOWN e o liveness vai junto. No e-commerce, às 10:27:15, um evento de pedido criado levou 73 segundos para ser consumido.

O método que cria o pedido de venda tinha um @Retry de duas tentativas com 30 segundos de espera entre elas: bastava uma falha do vendas para um único registro passar do limite.

O limite subiu para 120 segundos, e a chamada ganhou timeout e circuit breaker:

@Timeout(value = 20, unit = ChronoUnit.SECONDS)
@CircuitBreaker(requestVolumeThreshold = 10, failureRatio = 0.5,
    delay = 30, delayUnit = ChronoUnit.SECONDS, successThreshold = 2,
    skipOn = {ValidacaoException.class, NaoEncontradoException.class})
@Retry(maxRetries = 1, delay = 5, delayUnit = ChronoUnit.SECONDS,
    abortOn = {CircuitBreakerOpenException.class,
               ValidacaoException.class, NaoEncontradoException.class})
CreatePedidoResponse createPedidoVenda(CreatePedidoRequest request);

O pior caso de uma mensagem cai para uns 45 segundos (20 + 5 + 20). Erro de validação ou código 404 do vendas não conta como falha nem é repetido, porque repetir não muda a resposta.

E com o circuito aberto o retry desiste na hora, em vez de esperar para tomar a mesma recusa. Isso é MicroProfile Fault Tolerance, não Resilience4j, mas os conceitos são os mesmos dos posts sobre circuit breaker e retry.

O custo dessa escolha: com o circuito aberto, a mensagem vai para a DLQ e fica lá. Os consumers não informam URL de reprocessamento, então ninguém a reenvia sozinho.

Como reprocessar (um job de reconciliação, um tópico de retry com atraso, um endpoint manual) ainda não está decidido. Entre uma mensagem parada na fila e um pod reiniciando, escolhi a fila.

E a consistência?

Enquanto lia o fluxo procurando as quedas, achei seis bugs que deixavam um pedido preso em AGUARDANDO_REPLICACAO sem derrubar nada.

O mais traiçoeiro: o cadastro publicava a pessoa antes do próprio commit, e a confirmação de um serviço rápido podia chegar antes de a linha de acompanhamento existir. Ela era descartada com um WARN educado, e o pedido nunca andava.

A correção foi um pg_advisory_xact_lock por pessoa entre a criação do cliente e o consumer das confirmações. Os outros cinco, e por que cada um precisou de uma ferramenta diferente, ficam para outro post.

O que ficou

Da próxima vez, antes de abrir uma linha de código, eu olharia como o pod morre. Exit code 137 com liveness falhando conta uma história bem diferente de OOM, e teria me levado direto ao health check, que por sua vez estava configurado num lugar que ninguém lia.

No código, a pergunta que resolveu o financeiro foi simples e eu demorei para fazer: onde começa a transação em relação ao try/catch que deveria proteger o canal?

Duas coisas continuam em aberto. Não sei ainda se a rajada de callbacks esbarrou no limite de conexões do banco ou na CPU da instância. E os 34 consumers com o mesmo padrão do financeiro continuam lá, cada um esperando a sua falha de commit.