O caixa 01 perde a conexão com o banco no meio da confirmação de uma venda, os outros computadores também param, e alguns minutos depois tudo volta. O usuário quer registrar a venda de novo, e o caso separa quatro perguntas que costumam se misturar: se o servidor reiniciou, se o banco se recuperou, se a venda foi gravada e o que causou a interrupção.
O relato e as evidências
No dia 1º de outubro, por volta das 09:06, o caixa 01 da filial 01 perde a conexão enquanto confirma a venda VEN-0051. O balcão 01 e o balcão 02 também deixam de consultar o banco, e às 09:11 as consultas voltam a funcionar. O usuário pergunta se precisa registrar a venda de novo. O suporte recebe três materiais:
- o erro 2013, de conexão perdida durante a consulta, no registro do caixa 01, às 09:06:15;
- o final do log de erros do MySQL do servidor da loja, com a inicialização, a recuperação do InnoDB e o serviço pronto para conexões perto das 09:10, sem o período anterior;
- uma imagem do Visualizador de Eventos do servidor da loja, com um evento Crítico de ID 41 às 09:10:06.
Faltam os detalhes completos do evento, os registros anteriores à interrupção, a situação da venda e qualquer informação sobre intervenções no servidor. Ninguém relatou falta de energia.
O caixa perdeu a confirmação durante a operação, e o MySQL registrou uma inicialização depois disso. O resultado da venda e a causa da interrupção continuam desconhecidos e são perguntas diferentes. A consulta da VEN-0051 pelo procedimento do sistema responde à dúvida da venda e vem antes de qualquer repetição. Os eventos completos e os registros anteriores do servidor ajudam a separar um reinício do computador de uma parada só do serviço.
A linha do tempo
Os arquivos preservados cobrem das 08:55 às 09:20, e o fuso de cada origem foi confirmado. No servidor da loja, o Windows registra o evento Kernel-Power de ID 41 no canal Sistema às 09:10:06, e o log de erros do MySQL mostra a inicialização:
261001 9:10:38 InnoDB: Database was not shut down normally!InnoDB: Starting crash recovery.261001 9:10:52 [Note] mysqld: ready for connections.
No MySQL 5.1, o log de erros grava a data com dois algarismos para o ano, o mês e o dia, seguida da hora local do servidor, sem o fuso. Antes dessas linhas, o log não tem nenhum registro desde a inicialização anterior, alguns dias antes, o que é comum em um serviço sem erros. Por isso, o período sem linhas não diz quando o servidor parou.
O ID 41 é gravado na inicialização seguinte, e o horário dele, 09:10:06, não marca o instante da interrupção. A mensagem do InnoDB mostra que o banco não foi encerrado corretamente e é compatível com um desligamento abrupto, sem identificar a causa, e a falta de energia é só uma das possibilidades. O serviço pronto às 09:10:52 também não diz nada sobre a VEN-0051.
Outros resultados mudariam a direção da investigação. Uma parada só do MySQL, com o Windows em funcionamento e sem o ID 41, levaria a análise para o serviço e para o log dele. O início do Windows depois de um encerramento incorreto leva a análise para a interrupção do computador.
O desligamento forçado e o travamento anterior
O arquivo de eventos exportado confirma o início do Windows e o ID 41, com os detalhes BugcheckCode igual a 0 e PowerButtonTimestamp diferente de 0. Um responsável da loja relata, então, que o servidor deixou de responder por volta das 09:06 e que ele segurou o botão de energia para desligá-lo perto das 09:08. O relato entra no registro como a informação de uma pessoa, com o horário aproximado.
O PowerButtonTimestamp diferente de zero é compatível com o desligamento pelo botão e explica a intervenção entre o sintoma e o reinício. Ele não explica por que o servidor deixou de responder. O BugcheckCode igual a zero também não prova falta de energia nem descarta um travamento, porque um erro de parada pode não chegar a ser gravado. Os eventos anteriores não mostram a causa, e não havia coleta de desempenho no servidor.
Se os detalhes trouxessem um código de erro de parada, com o despejo de memória correspondente, a investigação seguiria por esse código. Um aviso de disco perto do horário, como o evento Disk de ID 7, precisaria ser ligado à ocorrência antes de ser tratado como causa.
A venda e a investigação que continua
O responsável consulta a VEN-0051 pela filial, pelo documento e pela referência, pelo procedimento do sistema. O histórico mostra a venda concluída, com os itens e a baixa de estoque correspondentes, e a evidência é preservada. O caixa perdeu só a confirmação, e a venda não precisa ser registrada de novo, porque uma segunda venda igual duplicaria os itens e a baixa de estoque.
A validação confirma a conexão, a consulta e a leitura desse documento, sem certificar o banco inteiro. As tabelas da venda usam o InnoDB, e a recuperação automática não pede reparo. Uma tabela MyISAM, no mesmo cenário, pediria a verificação do estado, porque o MyISAM não passa pela recuperação automática do InnoDB.
Para a causa em aberto, a equipe define a coleta de uma nova ocorrência: os eventos dos canais Sistema e Aplicativo, o log de erros do MySQL, os horários e os destinos dos clientes, as observações de recursos pelo administrador e o registro de qualquer intervenção. Sem uma nova ocorrência, o registro mantém a causa em aberto, sem declarar o problema resolvido.
O registro do atendimento
O registro separa o reinício, a venda e a causa:
- Ocorrência: em 1º de outubro, a venda VEN-0051 perdeu a confirmação no caixa 01 às 09:06:15, com o erro 2013;
- Evidências: o Windows do servidor da loja registrou o ID 41 às 09:10:06, e o MySQL fez a recuperação às 09:10:38 e ficou pronto às 09:10:52;
- Intervenção: o responsável desligou o servidor pelo botão perto das 09:08, depois que ele deixou de responder, o que é compatível com os detalhes do evento;
- Venda: a consulta pelo procedimento do sistema mostrou a VEN-0051 concluída, com os itens e a baixa de estoque, sem repetição;
- Pendências: a causa do travamento anterior não foi identificada, a falta de energia não foi confirmada, e a coleta de uma nova ocorrência está definida.
No suporte
Diante de um servidor que reiniciou no meio de uma operação, convém tratar separadamente o resultado da operação, a volta do serviço e a causa da interrupção. A intervenção que desligou o computador e o problema que a motivou também entram no registro como fatos distintos.
Para guardar
- O ID 41 é gravado na inicialização seguinte e não identifica, sozinho, a causa da interrupção.
- A recuperação do InnoDB mostra um encerramento incorreto, e não a causa dele.
- O serviço disponível não confirma o resultado da operação que perdeu a resposta.
- O PowerButtonTimestamp diferente de zero indica o desligamento pelo botão, e não o motivo dele.
- Uma conclusão limitada, com as evidências e a próxima coleta, permite continuar o atendimento.
O MySQL voltou a aceitar conexões às 09:10:52. Isso resolve a dúvida sobre a venda VEN-0051?
Não. A volta do serviço não diz se a venda foi gravada antes da queda. Só a consulta da venda pelo procedimento do sistema mostra se ela foi concluída, se ficou pela metade ou se não existe, e cada resultado pede um caminho diferente.
Se o evento 41 trouxesse um BugcheckCode diferente de zero, o que mudaria?
O código indicaria um erro de parada, a tela azul, como causa do reinício. A investigação seguiria pelo código, convertido para hexadecimal, e pelo despejo de memória, quando existe, e o desligamento pelo botão deixaria de explicar o reinício.