Passei os últimos dias construindo o HookSafe, uma camada que fica entre a plataforma de pagamento e o servidor do cliente para garantir que nenhum webhook se perca. A promessa do produto é uma só: se o seu servidor cair, eu seguro o evento e insisto até entregar.
Cometi três bugs no caminho. O que me fez escrever este texto não foi a burrice de cada um, foi perceber, depois, que os três tinham a mesma forma: todos faziam uma falha parecer um sucesso. Num sistema cujo produto é confiabilidade, é difícil imaginar categoria de bug mais cruel.
Bug 1: engoli o erro, e o sistema jurou que tinha entregue
A função que entrega o evento no servidor do cliente ficou assim:
go
resposta, err := clienteHTTP.Do(requisicao)
if err != nil {
return "", nil // <- olhe com carinho
}
Eu quis escrever return "", err. Escrevi nil.
O efeito: apontei o destino para uma porta onde não havia nada escutando. O Do devolveu um belo connection refused. E a minha função respondeu ao worker: "sem erro, chefe". O worker, obediente, marcou o evento como entregue, com o status da resposta vazio, e seguiu a vida.
No banco:
id | pedido_id | status | tentativas | resposta
----+-----------+----------+------------+----------
6 | 9002 | entregue | 0 |
Um evento que nunca saiu do lugar, registrado como entregue. Se isso estivesse em produção, um cliente teria pagado, não receberia nada, e o meu painel mostraria, orgulhoso, que a entrega foi um sucesso.
Aquele if err != nil { return err } que a gente reclama de repetir em Go existe exatamente por isso. A linguagem te obriga a decidir o que fazer com a falha, toda vez. O preço da verbosidade é que ninguém engole um erro sem querer... a menos que digite nil.
Bug 2: o log mentiu
Corrigi o primeiro bug, rodei de novo, e o worker começou a cuspir isto, a cada cinco segundos, para sempre:
worker: erro ao marcar morto 7: ERROR: column "reposta" does not exist
worker: evento 7 esgotou as tentativas, marcado como MORTO
Leia as duas linhas de novo. A primeira diz que falhou ao gravar. A segunda anuncia que gravou.
O código:
go
if erroBanco := repo.MarkDead(ctx, evento.ID, descricao); erroBanco != nil {
log.Printf("erro ao marcar morto %d: %v", evento.ID, erroBanco)
}
log.Printf("evento %d esgotou as tentativas, marcado como MORTO", evento.ID)
Faltou um continue. O log de sucesso rodava sempre, tivesse a operação funcionado ou não.
O bug original era bobo: escrevi reposta em vez de resposta num UPDATE. Mas o reposta só me custou um minuto depois que eu vi a mensagem de erro. O que quase me custou uma hora foi o log seguinte, afirmando com todas as letras que o evento tinha sido marcado como morto. Eu fui olhar o banco procurando entender por que um evento "morto" continuava sendo processado, quando a resposta estava na linha de cima da minha própria tela.
Um log que mente é pior que a ausência de log. Sem log você sabe que não sabe. Com um log mentiroso, você depura com confiança na direção errada.
E o efeito colateral era divertido: como o MarkDead falhava, o evento nunca saía do status falhou, o next_retry_at já tinha vencido, e o worker o pegava de novo, e de novo, e de novo. Um loop infinito construído a partir de um "s" faltando.
Bug 3: cinco nanossegundos
O worker deveria acordar a cada cinco segundos. Configurei assim:
go
WorkerInterval: lerDuracao("WORKER_INTERVAL", 5),
E o log saiu assim:
23:00:09 worker: procurando eventos pendentes...
23:00:09 worker: procurando eventos pendentes...
23:00:09 worker: procurando eventos pendentes...
[mais algumas centenas de milhares de linhas no mesmo segundo]
time.Duration, em Go, é um int64 que conta nanossegundos. O literal 5, num lugar que espera uma time.Duration, vira time.Duration(5), que é cinco nanossegundos. O certo é 5 * time.Second, porque time.Second é a constante que vale um bilhão.
Esse é o mais inofensivo dos três, e o único que se anuncia na cara. Mas ele tem um parente perigoso: se você lê a variável de ambiente com time.ParseDuration, o valor precisa vir com unidade ("5s"). Se alguém setar WORKER_INTERVAL=5, o parse falha, o código cai no valor padrão em silêncio, e você fica sem entender por que a configuração não pega.
Ou seja, mesmo o bug bobinho tem uma versão dele que se disfarça de sucesso.
O padrão
Escrevi os três esperando que o texto virasse uma lista de descuidos. Virou outra coisa.
O erro engolido transformou uma falha de rede em uma entrega bem-sucedida. O log mentiroso transformou um UPDATE que não aconteceu em uma confirmação. O parse silencioso transforma uma configuração inválida em um valor padrão. Nenhum dos três derruba o sistema. Todos os três fazem o sistema afirmar com confiança algo que não é verdade.
Software que quebra é chato. Software que mente é caro. E existe uma classe inteira de bugs, os mais difíceis de achar, cuja assinatura é exatamente essa: o caminho de falha existe, mas ele foi escrito para parecer o caminho de sucesso.
O antídoto não é elegante. É desconfiar de todo lugar onde você decide, você mesmo, o que significa "deu certo": todo err que você não propaga, todo log de sucesso que não está guardado atrás de uma verificação, todo valor padrão que substitui uma entrada inválida sem avisar.
Se o seu sistema promete confiabilidade, ele precisa começar sendo honesto consigo mesmo.
O código é aberto: github.com/Rupelio/hooksafe. É um projeto de estudo, e as decisões de arquitetura estão registradas em ADRs no repositório, incluindo a chave de idempotência, que errei duas vezes antes de acertar. Mas essa é outra história.
Top comments (0)