Pular para conteúdo

0018 — Recência do evento e normalização incremental

Status: Aprovado · Responsável: Gustavo Madruga · Atualizado em: 2026-09-08 · Decidido em: 2026-09-04

Contexto

Em 2026-09-04 o pedido 260065713 (VIVA+ SOLAR, R$ 9.054,96) foi importado no X-Adm às 18:23Z (CodRetorno 006) e, três minutos depois, alarmou como "cancelado na PIED" — o alerta de cancelamento pós-import (0010). A Maxsul confirmou: ninguém cancelou nada.

O raw contava outra história. Ordem real dos eventos do pedido:

quando (UTC) fonte payment.status
13:19 REST requested
14:24 webhook cancelled
17:08 REST cancelled (mesmo snapshot das 14:24)
18:13 webhook requested
18:17 webhook received

O cancelled das 14:24 é legítimo, porém velho: uma tentativa de pagamento no cartão que caiu, quatro horas antes do import. O estado real na PIED era — e seguiu sendo — received.

A causa raiz estava no NormalizadorService: normalizarCronologico() reprocessava todo o raw histórico a cada rodada (5 min), em ordem cronológica. Cada rodada refazia a história inteira do pedido — requested → cancelled → requested → received. Enquanto o pedido era CAPTURADO isso era inofensivo; depois do import não era mais: na primeira rodada após o CONFIRMADO, a reaplicação do cancelled de 14:24 satisfez o guard de cancelado_pied_em (status = CONFIRMADO e payment_status <> 'cancelled' e novo = 'cancelled') e disparou o e-mail. Falso positivo — e, pior, set-once: o carimbo queimou o alerta de um cancelamento real futuro daquele pedido.

O mesmo replay tinha um irmão silencioso: pago_em era re-carimbado a cada rodada (a transição cancelled → received era refeita toda vez), então a data que o painel mostra andava de 5 em 5 minutos. E o custo: 21 mil pedidos re-upsertados por rodada.

O replay era só o gatilho mais provável. O problema de fundo é que a normalização não tinha noção de recência: qualquer snapshot atrasado — uma página REST que chega depois de um webhook mais novo, um reprocesso manual — reaplica um payment.status vencido e mexe nos guards de transição.

Decisão

Duas defesas, em camadas diferentes e independentes.

A — Guard de recência no upsert de pied_pedido

O ON CONFLICT ... DO UPDATE ganhou um WHERE: o evento só é aplicado se não for mais antigo que o já persistido.

WHERE pied_pedido.last_update IS NULL
   OR EXCLUDED.last_update IS NULL
   OR date_trunc('second', EXCLUDED.last_update)
      >= date_trunc('second', pied_pedido.last_update)
  • Empate aplica (>=, não >), de propósito: o enriquecimento rebusca no REST o mesmo snapshot só para trazer o invoice. Um > estrito prenderia o pedido na fila para sempre — a cura seria pior que a doença.
  • Sem last_update dos dois lados, aplica: sem informação de recência não há como julgar; é o comportamento anterior, preservado.
  • last_update passou a ser gravado com COALESCE(EXCLUDED.last_update, pied_pedido.last_update): um payload sem lastUpdate não zera a referência que arma o guard.
  • upsert agora devolve boolean (linha afetada ou não). O NormalizadorService só chama alertarCancelamentoPosImport quando o upsert de fato aplicou — sem isso o alerta dispararia a partir de um evento que o banco recusou, que é exatamente o bug com outro nome.

O guard cobre todos os efeitos de transição de uma vez: cancelado_pied_em, pago_em, parcial_desde, o gate CAPTURADO → NA_FILA, deal_status_anterior e o payload.

A.1 — Correção 2026-09-08: comparar no segundo cheio, não no milésimo

A primeira versão do guard comparava last_update cru — e a cura virou a doença que ela mesma previa. As duas fontes carimbam o mesmo instante com precisões diferentes:

Fonte lastUpdate do pedido 260074525
webhook (order.updated) 2026-09-08T11:54:24.512Z
REST (GET /requests/order/...) 2026-09-08T08:54:24-03:00 (= 11:54:24.000Z)

O milésimo do webhook põe a linha num futuro que o REST nunca alcança: .000 >= .512 é falso, o enriquecimento buscava a página certa (com invoice) e era recusado toda rodada, e o pedido morava em NA_FILA — sem invoice, sem cliente, sem erro e sem alerta. Cinco pedidos presos assim em 2026-09-08 (260074525, 260079167, 260079176, 260079300, 260079309).

A comparação passou a truncar os dois lados no segundo (date_trunc('second', …)). O empate por truncamento é o mesmo caso que o >= já cobria de propósito: o mesmo snapshot por outra fonte. O que se perde é distinguir dois eventos reais dentro do mesmo segundo — a PIED não produz isso, e empate já aplicava.

Destravar quem já está preso (o guard não reescreve o passado): truncar a referência das linhas paradas e deixar a rodada seguinte aplicar o REST.

UPDATE pied_pedido SET last_update = date_trunc('second', last_update) WHERE status = 'NA_FILA';

O "Re-normalizar" do console não serve para isso, e piora: ele reaplica o próprio payload (que traz o lastUpdate com milésimos), então o COALESCE re-carimba a referência e re-arma o guard contra o REST. Ele relê a linha, nunca o pied_rest.

B — Normalização incremental (pied_normalizacao_estado, migração V11)

A rodada passa a ler só o raw novo. Cursor singleton (id = 1, molde de pied_integracao_estado/pied_watchdog_estado) guardando o max(recebido_em/buscado_em) do raw processado — não now(), para não pular o que ainda não tinha commitado.

Duas escolhas de projeto ficam explícitas:

  • Margem de segurança de 10 min. O timestamp do raw é o momento da captura, mas a linha só fica visível no commit: um webhook pode commitar depois de uma página REST mais nova e ficaria eternamente atrás do cursor — perdido, em silêncio. A rodada revisita os 10 minutos anteriores ao cursor. Reprocessar essa janela é barato e, sob o guard (A), inofensivo.
  • O cursor nunca retrocede (GREATEST no avancar): nem duas instâncias, nem o reprocesso da margem podem puxá-lo para trás e ressuscitar o replay.

Índice novo idx_pied_rest_buscado_em: o recorte varre pied_rest só por buscado_em (todas as entidades juntas, em ordem cronológica global) e o índice da V1 é (entidade, buscado_em).

Reprocesso completo (quando for preciso reconstruir a normalizada do zero) é uma linha:

UPDATE pied_normalizacao_estado SET ate_ts = NULL;

Deliberadamente sem botão no console: é operação rara, e com o guard (A) já não há a promessa mágica de "reprocessar conserta" — evento velho continua velho.

Consequências

  • O falso alerta de cancelamento pós-import não volta, nem por replay nem por página REST atrasada.
  • pago_em para de andar; passa a ser o carimbo estável que o 0010 prometeu.
  • A rodada de 5 min deixa de re-upsertar toda a base — custo proporcional ao raw novo.
  • Trade-off aceito: uma página REST estritamente mais antiga que traria um invoice inédito é descartada pelo guard. Na prática o enriquecimento devolve o snapshot corrente (empate, que passa), e o caso residual se resolve na rodada seguinte com dado mais fresco.
  • Fora de escopo: pied_cliente/pied_produto não têm noção de recência (não carregam lastUpdate) e seguem com upsert "último a escrever vence" — não há guard de transição nem alerta pendurado neles, então o risco é cosmético.
  • Dado sujo do incidente: o cancelado_pied_em do 260065713 ficou carimbado. Limpá-lo (para destravar o alerta real futuro) só faz sentido depois deste deploy — antes, a rodada seguinte re-carimbava em 5 minutos.

Alternativas descartadas

  • Blindar só o alerta (checar lastUpdate dentro de alertarCancelamentoPosImport): remendo no sintoma. Deixaria pago_em, o gate e o payload ainda sujeitos ao evento retroativo.
  • Ordenar o replay por lastUpdate em vez do timestamp de captura: não resolve — o replay reaplica a história inteira de qualquer jeito, e lastUpdate pode faltar no payload.
  • Só (B), sem o guard: mataria o replay, mas não a página REST atrasada chegando depois de um webhook novo — o mesmo falso alerta por outro caminho. As duas defesas cobrem camadas distintas.