O erro da primeira alteração do dia quase nunca é azar

Um erro que acontece «de vez em quando, na primeira alteração do dia» quase nunca é azar. Costuma ser uma conexão que ficou adormecida, um cache que guardou algo que já não serve ou um relógio de que ninguém se lembra. E é possível prová-lo antes de corrigi-lo.

Imagine uma manhã qualquer em uma loja on-line. A pessoa que cuida do catálogo chega, abre o sistema e faz a primeira alteração do dia: corrige a descrição de um produto e salva. Tudo parece normal. Meia hora depois, alguém de vendas escreve preocupado: esse produto aparece no buscador da loja sem preço e sem estoque. Ou pior, já não aparece.

Ninguém mexeu no preço. Ninguém apagou nada. A pessoa do catálogo abre o produto de novo e o salva outra vez sem mudar nada. O produto volta completo. Registra-se como «um detalhe» e o dia segue. Na próxima vez que acontece, dias ou semanas depois, alguém volta a «consertá-lo à mão».

No caso que contamos aqui, quem o vivia calcula que conviveu com essa falha por muito tempo. Quando finalmente alguém a contou, em testes, ela apareceu várias vezes em um único mês. E sempre tinha a mesma forma: um único produto, o primeiro que era editado no dia.

Este artigo é para quem dirige operação ou tecnologia e para a equipe que mantém os sistemas. Ele cobre quatro coisas:

1. O que acontecia de verdade.
2. Por que esses erros sobrevivem por anos.
3. Como se prova e se corrige: reproduzir a falha de propósito, corrigir a causa, impedir que uma falha escreva dados quebrados e validar comparando o antigo com o novo.
4. O que perguntar no próximo comitê e por onde começar esta semana.

O que acontecia de verdade

O buscador de uma loja on-line quase nunca lê direto do banco de dados onde vive o catálogo. Ele lê de um índice de busca: uma cópia do catálogo organizada para encontrar rápido. Entre os dois há um processo que copia cada alteração. Ele pode ser montado, por exemplo, com MariaDB como banco, Logstash como o processo que copia e Elasticsearch como o índice. Esse processo trabalha o dia todo: a cada minuto pergunta «o que mudou?» e leva as alterações ao índice.

Para montar cada produto, o processo precisa fazer uma segunda consulta ao banco: trazer suas variantes, isto é, as versões de um mesmo produto, cada uma com seu preço e seu estoque. Para não abrir uma conexão nova a cada vez, ele mantém uma aberta e a reutiliza.

O problema começa à noite. Ninguém edita produtos, então essa conexão fica parada por muitas horas. E o banco de dados, por projeto, fecha as conexões que estão há muito tempo sem atividade. No MariaDB e no MySQL, para as conexões de programas (não as de uma pessoa no console), esse tempo se chama wait_timeout e, se ninguém o altera, vale 28.800 segundos: oito horas [1][2]. O manual do MySQL diz isso sem rodeios: por padrão, o servidor fecha a conexão depois de oito horas se nada aconteceu [3].

O banco fecha o seu lado, mas o processo não fica sabendo. Continua guardando a conexão como se estivesse viva. Na manhã seguinte chega a primeira alteração, o processo usa essa conexão morta e a consulta de variantes falha. O cliente do banco só descobre que a conexão já não existe quando tenta usá-la [3]. Em Java, com o driver do MySQL (a peça de software que conversa com o banco em nome do programa), o mesmo evento aparece como «Communications link failure». O próprio driver sugere a causa: um tempo sem uso mais longo que o wait_timeout do servidor [4].

Até aqui seria um erro que se tenta de novo e pronto. O que o torna caro é o que acontece depois.

A falha que escreve por cima do dado bom

Quando a consulta de variantes falha, um filtro como o jdbc_streaming do Logstash não detém o produto. Ele lhe acrescenta uma etiqueta de erro e coloca o valor padrão no campo de variantes. Se ninguém configurou esse valor, o campo fica como uma lista com um único elemento vazio: o produto fica sem dados de variantes. E o filtro o deixa seguir seu caminho [7]. O código do filtro mostra isso com clareza; a documentação só o menciona de passagem, ao descrever o cache (cache_expiration) [5].

O produto, agora sem variantes, chega ao índice de busca. E o índice o grava com o mesmo identificador que o produto bom já tinha. Esse detalhe, que normalmente é uma virtude, aqui é o dano. Com a ação de gravação habitual (index) sobre um índice comum, gravar um documento com um identificador que já existe atualiza o documento inteiro e incrementa sua versão [15][16]. Não fica um produto quebrado ao lado do bom; fica o quebrado no lugar do bom.

No caso, a segunda alteração do dia já não falhava: o mais provável é que, após o erro, a conexão morta fosse descartada e outra fosse aberta. Isso depende do driver e do gerenciador de conexões, não do filtro; convém confirmá-lo no log. Por isso a edição seguinte «o consertava» e o erro só atingia o primeiro.

Três suspeitos de sempre: uma conexão, um cache ou um relógio

O caso tem nomes próprios, mas o padrão não. Quando um erro aparece «de vez em quando» e quase sempre no mesmo horário do dia, ou depois de um fim de semana, convém procurar algo que tenha um temporizador.

Uma conexão adormecida. O corte pode vir de três lugares, e o cliente só fica sabendo quando volta a usar a conexão:

• O banco de dados, como neste caso: oito horas por padrão no MariaDB e no MySQL [1][2].
• A rede. Na Amazon Web Services (AWS), por exemplo, a porta de saída para a internet de uma rede privada (NAT Gateway) dá por expirada uma conexão que passa 350 segundos ou mais sem atividade. A quem tentar continuar usando-a, responde com um pacote de reinício do TCP (RST), que corta a conexão [11]. O balanceador de rede da AWS, que distribui as conexões entre vários servidores, também corta aos 350 segundos por padrão. Em conexões TCP esse valor pode ser configurado entre 60 e 6.000 segundos [12]. Um firewall, o equipamento que filtra o tráfego entre duas redes, pode fazer o mesmo sem avisar ninguém. O Internet Storm Center do SANS documentou em 2007 um caso assim: um firewall apagava as sessões com uma hora sem uso entre um servidor de aplicações e um banco Oracle [13].
• O sistema operacional. O mecanismo que mantém as conexões vivas (keepalive do TCP) depende do sistema operacional e de como cada conexão foi aberta. No caso do SANS, ele começava às duas horas, tarde demais para o firewall [13].

Um cache. Um cache é uma memória de curto prazo: guarda uma resposta para não ter de pedi-la de novo. Se guarda uma resposta vazia ou errada, repete-a até vencer. Um filtro como o jdbc_streaming, por exemplo, com seu cache ligado (vem assim por padrão), pode fazer isso. Diante de um erro passageiro, guarda o resultado vazio para esses parâmetros até que vença o seu tempo, cinco segundos por padrão [5][7].

Um relógio. Muitos processos de cópia decidem o que ler com um horário: «traga o que mudou depois da última vez». Esse horário se chama marca d'água [6], e tem uma armadilha que veremos adiante: nem sempre diz o que se imagina.

Por que esses erros sobrevivem por anos

Um diretor pode se perguntar, com razão, como um erro que todos viram pode durar tanto. A resposta quase nunca é descuido. É que esse tipo de erro tem quatro traços que o protegem:

• Ele se corrige sozinho. A edição seguinte deixa o produto certo. Um erro que se corrige sozinho destrói a própria evidência: quando alguém de tecnologia chega para revisar, já não há nada para ver.
• Ninguém o reproduz. Para vê-lo, é preciso esperar uma noite inteira sem atividade e fazer uma alteração logo depois. Ninguém faz isso em um dia normal de trabalho. Assim, o erro nunca aparece quando alguém o está procurando.
• É consertado à mão e esquecido. Salvar o produto de novo leva um minuto. Sem chamado não há contagem, e sem contagem não há prioridade.
• O sintoma aparece longe da causa. Quem vê o problema é vendas, no buscador. A causa está em um acordo de tempos entre duas máquinas que ninguém havia escrito. Vendas não sabe que essa conexão existe, e quem a configurou não vê o buscador.

Como se prova e se corrige

A tentação, quando finalmente alguém suspeita da causa, é mudar a configuração e esperar. Se o erro deixa de aparecer, dá-se por resolvido. O problema é que «deixou de aparecer» é exatamente o que já acontecia entre uma falha e a seguinte. Uma falha intermitente se prova antes de ser corrigida. Estes são os quatro passos que seguimos.

1. Reproduzi-la de propósito

Se a falha depende de um relógio, encurta-se o relógio. Em um ambiente de testes, a equipe reduz o wait_timeout do banco para, digamos, 60 segundos. Há um detalhe que muita gente deixa passar: cada conexão assume esse valor no momento em que é aberta [1][2]. Reduzir o valor geral não afeta as conexões que já existem. Por isso, o prático é reiniciar o processo de cópia, para que sua conexão nasça com o valor curto.

Depois, espera-se um par de minutos, edita-se um produto e observa-se. No log do processo aparece a etiqueta de erro do filtro; no índice, o produto sem variantes. Um teste de minutos substitui uma espera de oito horas.

O teste que convence a todos é o do tempo real. Em um teste controlado, depois de mais de 10 horas sem atividade, a primeira edição falhou e a seguinte saiu certa. Era o sintoma exato que o negócio via, provocado de propósito e com hora marcada.

2. Corrigir a causa, não o sintoma

Há três respostas padrão para uma conexão que adormece, e elas são as mesmas em quase qualquer tecnologia: validá-la antes de usá-la, renová-la antes que expire ou mantê-la acordada com tráfego periódico.

Em um filtro como o jdbc_streaming do Logstash, por exemplo, a primeira é uma opção: jdbc_validate_connection, que vem desligada por padrão [5]. Ao ligá-la, o processo verifica a conexão antes de usá-la. Se estiver morta, ele a descarta e abre outra [8][9].

Aqui está a nuance que quase ninguém lê. A opção que a acompanha, jdbc_validation_timeout, vem documentada como «a cada quanto tempo validar» e vale 3.600 segundos por padrão [5]. Na realidade, funciona de outro modo: a biblioteca que gerencia as conexões só verifica as que estão há mais desse tempo sem uso [9]. Uma conexão que passou a noite parada está há muito mais de uma hora inativa. Assim, com o valor padrão ela é verificada, e o corte de oito horas do banco fica coberto.

Mas o corte pode vir da rede e ser mais curto, como os 350 segundos de um balanceador ou de um NAT. Aí uma conexão com dez minutos sem uso não seria verificada e chegaria morta. Contra esse corte é preciso outra medida: reduzir esse limite para abaixo do corte, ou manter a conexão viva com tráfego mais frequente que o corte [11].

Em Java, o princípio é o mesmo. O HikariCP, um gerenciador de conexões muito usado, recomenda que a vida máxima de uma conexão seja alguns segundos mais curta que qualquer limite do banco ou da infraestrutura. Ele também oferece mantê-las vivas com uma verificação periódica [10]. E o driver do MySQL para Java desaconselha sua opção de reconexão automática [4]: reconectar às cegas não é a resposta oficial.

3. Impedir que uma falha escreva dados quebrados

Corrigir a conexão evita o erro de cada manhã. Não evita o próximo erro que ninguém imaginou. Por isso a segunda mudança importa tanto quanto a primeira: se uma parte do produto não pôde ser trazida, nada é escrito.

Com o Logstash, por exemplo, isso se consegue com uma condição depois do filtro. Se o produto traz a etiqueta de erro da consulta (_jdbcstreamingfailure), ele é descartado e não chega ao índice [7]. O produto anterior, completo, fica onde estava.

É preciso distinguir dois casos que se parecem. O produto que falhou leva duas etiquetas: a de erro e a de «foi usado o valor padrão» (_jdbcstreamingdefaultsused) [7]. Um produto que de fato não tem variantes leva só a segunda. Por isso a condição olha apenas a de erro: o produto sem variantes continua sendo copiado, de propósito, e só o que falhou ao consultá-las é detido.

Essa decisão tem um custo, e é preciso dizê-lo. Se a consulta só pede o que é posterior à marca d'água e a marca já avançou, a alteração descartada não se recupera sozinha. Assim funcionava no caso; em outro sistema, convém confirmar isso com a consulta real. O produto fica com sua versão anterior até que alguém o edite de novo ou o índice seja recarregado. Para um diretor, a regra se entende sem código: melhor o preço de ontem do que nenhum preço. Um produto com o dado de ontem vende; um sem preço desaparece.

A lição de fundo, para a equipe técnica: usar o identificador do produto como identificador no índice torna inofensivo repetir uma carga, porque o resultado final é o mesmo [15]. Essa mesma propriedade é a que causa dano quando o documento vem incompleto. Que uma carga possa ser repetida sem dano não a torna segura: também é preciso que ela não escreva quando algo falta.

4. Revisar o relógio e validar contra o antigo

O processo de cópia decide o que copiar com uma marca d'água: «traga o que mudou depois do último horário que vi» [6].

A armadilha é que o horário que se guarda como «última modificação» nem sempre é o horário em que a alteração ficou gravada. Dois termos ajudam. Uma instrução é uma ordem que se dá ao banco, como «mude este preço». Uma transação é um pacote de instruções que é gravado todo junto ou não é gravado; confirmá-la é o momento em que sua alteração fica gravada e os demais podem vê-la.

No MySQL, NOW() devolve o horário em que a instrução começou, não o horário em que foi confirmada [14]. Suponha que a coluna de última modificação seja preenchida com NOW(), e que uma alteração grande demore para ser gravada: começa às 10:00 e confirma às 10:03. Suas linhas dizem «10:00». Enquanto isso, o processo de cópia já leu alterações mais novas e moveu sua marca para além disso. Quando a alteração grande finalmente confirma, suas linhas trazem um horário anterior à marca, e a leitura seguinte já não as pede. Elas se perdem em silêncio. Esse risco é da mesma família de limites que a equipe do Debezium aponta sobre a captura de alterações por consulta periódica: ela pode perder alterações intermediárias e não vê as exclusões [17].

Há duas formas de fechar essa porta:

• Uma margem de tempo. «Só leio o que tem pelo menos um minuto de idade.» A marca já não avança sobre segundos que ainda podem receber alterações. Isso reduz o risco, mas não é uma garantia: uma transação que demore mais de um minuto para confirmar ainda pode se perder.
• Ler o log do banco em vez de uma coluna com horário. É o que se chama de captura de alterações por log (CDC, na sigla em inglês). Um exemplo é o Debezium lendo o log binário do MariaDB ou do MySQL. Esse log guarda as operações na ordem em que foram confirmadas, incluindo as exclusões [17][18]. Bem configurado, fecha essa janela em particular, em troca de mais peças para configurar e operar.

No caso que contamos, escolheu-se a margem de um minuto, com seu limite registrado por escrito.

Resta a pergunta que todo diretor deveria fazer: como sabemos que a correção não quebrou nada que antes funcionava? A resposta do caso foi uma comparação completa. A consulta antiga e a nova foram executadas sobre todo o catálogo, em testes, e deram exatamente o mesmo resultado. A consulta nova só mudou quando lê. Qualquer diferença teria sido um erro novo. Não houve nenhuma.

E depois, outra vez o teste da noite. Em um teste controlado, depois de mais de 16 horas sem atividade, a primeira edição entrou sem erro: o caso exato que antes falhava. Além disso, os produtos que tinham ficado quebrados foram consertados, e ao fim da revisão não restava nenhum quebrado em testes.

Cinco perguntas para o próximo comitê

1. Quais erros «se corrigem sozinhos» nos nossos sistemas? Pergunte a vendas, ao atendimento ao cliente e a quem opera o catálogo, não só a tecnologia. As melhores pistas costumam estar com quem conserta à mão.
2. Algum acontece sempre no mesmo horário, na segunda-feira ou depois de uma noite sem uso? Se a resposta for sim, há um relógio por trás.
3. Sabemos quanto tempo cada conexão entre nossos sistemas aguenta sem uso, e quem a corta primeiro: o banco, a rede ou a nuvem? Se ninguém tem isso por escrito, ninguém o decidiu.
4. Quando um processo não consegue trazer toda a informação, o que ele faz? Deixa o que havia ou publica algo pela metade?
5. Quando tecnologia diz «já ficou pronto», como provou isso? Provocou a falha antes da correção e voltou a provocá-la depois, ou só deixou de vê-la?

Se duas ou mais respostas forem «não sei», o problema não é de sorte: falta medir.

Por onde começar esta semana

Não é preciso um projeto. É preciso uma lista. Peça às áreas que operam os sistemas que anotem, durante duas semanas, cada vez que algo «se corrigiu sozinho» ou «foi consertado à mão»: o que foi, a que horas e o que se fez. Ao fim das duas semanas, ordene a lista por horário. Se várias entradas se concentram logo no começo da manhã ou depois de um fim de semana, já existe o primeiro suspeito. À equipe técnica basta uma tarde para começar a reproduzi-lo em um ambiente de testes.

O que a Hábil faz

Quando uma falha se repete, a Equipe SWAT da Hábil busca a causa de fundo, não outro reinício: ela a reproduz, a corrige e entrega a evidência de como foi verificada, para que possa ser revisada.

A primeira conversa é sem custo: o objetivo é ajudar a localizar qual falha se repete, desde quando e como pode ser provada. Escreva para nós pelo WhatsApp.