Mergulhando de cabeça nos logs

Quando entrei na Amazon depois da faculdade, um dos meus primeiros exercícios de integração era colocar o servidor da web amazon.com em funcionamento no meu computador de desenvolvedor. Não entendi direito na primeira tentativa e não tinha certeza do que fiz de errado. Um colega de trabalho bem prestativo sugeriu que eu olhasse os logs para ver o que estava errado. Para fazer isso, ele disse que eu deveria "cat the log file", o que eu entendi como "usar um gato no arquivo de log". Eu estava convencido de que ele estava fazendo algum tipo de brincadeira comigo ou fazendo uma piada sobre gatos que eu não entendi. Eu só usei o Linux na faculdade para compilar, usar o controle de origem e usar um editor de texto. Então, eu não sabia que "cat" é, na verdade, um comando para imprimir um arquivo no terminal que eu poderia alimentar em outro programa para procurar padrões.

Meus colegas de trabalho me indicaram ferramentas como cat, grep, sed e awk. Equipado com esse novo conjunto de ferramentas, mergulhei nos logs do servidor da web amazon.com no meu computador de desenvolvedor. O aplicativo do servidor web já estava instrumentado para emitir todos os tipos de informações úteis nos logs dele. Isso me permitiu ver qual configuração eu não estava percebendo que impedia a inicialização do servidor da Web, que mostrava onde ele poderia estar travando ou que indicava onde estava falhando ao conversar com um serviço de recebimento de dados. O site é composto de muitas peças em movimento, e era essencialmente uma caixa preta para mim no começo. No entanto, depois de mergulhar de cabeça no sistema, aprendi como descobrir como o servidor funcionava e como interagir com suas dependências apenas observando a saída da instrumentação.

Por que a instrumentação?

Ao passar de equipe para equipe ao longo dos anos na Amazon, descobri que a instrumentação é uma lente inestimável que eu e outros na Amazon procuramos para aprender como funciona um sistema. No entanto, a instrumentação é útil para mais do que apenas aprender sobre sistemas. É o núcleo da cultura operacional na Amazon. Uma ótima instrumentação nos ajuda a ver a experiência que estamos oferecendo aos nossos clientes.
 
Esse foco na performance operacional abrange a empresa. Nos serviços associados ao amazon.com, o aumento da latência resulta em uma experiência de compra ruim e, portanto, reduz as taxas de conversão. Com os clientes que usam a AWS, eles dependem da alta disponibilidade e baixa latência dos serviços da AWS.
 
Na Amazon, não consideramos apenas a latência média. Nós nos concentramos ainda mais em discrepantes de latência, como os percentis 99,9 e 99,99. Isso ocorre porque se uma solicitação de 1.000 ou 10.000 solicitações for lenta, isso ainda será uma experiência ruim. Descobrimos que, quando reduzimos a latência de alto percentil em um sistema, nossos esforços têm o efeito colateral de reduzir a latência mediana. Por outro lado, descobrimos que, quando reduzimos a latência mediana, isso reduz a latência de alto percentil com menos frequência.
 
A outra razão pela qual nos concentramos na latência de alto percentil é que a alta latência em um serviço pode ter um efeito multiplicador em outros serviços. A Amazon se baseia em uma arquitetura orientada a serviços. Muitos serviços colaboram entre si para fazer algo, como renderizar uma página da Web no amazon.com. Como resultado, um aumento na latência de um serviço profundo na cadeia de chamadas, mesmo que o aumento esteja em um percentil alto, tem um grande efeito cascata na latência experimentada pelo usuário final.
 
Os grandes sistemas na Amazon são compostos de muitos serviços de cooperação. Cada serviço é desenvolvido e operado por uma única equipe (grandes "serviços" são compostos de vários serviços ou componentes nos bastidores). A equipe que possui um serviço é conhecida como a proprietária do serviço. Todo membro dessa equipe pensa como proprietário e operador do serviço, seja ele desenvolvedor de software, engenheiro de rede, gerente ou ocupante de qualquer outra função. Como proprietários, as equipes estabelecem metas para a performance de todos os serviços associados. Também garantimos a visibilidade das operações de serviço, a fim de garantir o cumprimento dessas metas, a solução de quaisquer problemas que surgirem e a manutenção de metas ainda mais altas no ano seguinte. Para definir metas e obter essa visibilidade, as equipes devem instrumentar os sistemas.
A instrumentação também nos permite detectar e responder a eventos operacionais taticamente.
 
A instrumentação alimenta os dados nos painéis operacionais, para que os operadores possam visualizar as métricas em tempo real. Ele também alimenta os dados em alarmes, que acionam e envolvem os operadores quando o sistema está se comportando de maneira inesperada. Os operadores usam a saída detalhada da instrumentação para diagnosticar rapidamente por que as coisas deram errado. A partir daí, podemos mitigar o problema e voltar mais tarde para impedir que o problema ocorra novamente. Sem boa instrumentação em todo o código, dedicamos um tempo precioso ao diagnóstico de problemas.

O que medir

Para operar os serviços de acordo com nossos altos padrões de disponibilidade e latência, nós, como proprietários de serviços, precisamos medir como os nossos sistemas se comportam.

Para obter a telemetria necessária, os proprietários do serviço medem a performance operacional de vários locais para obter várias perspectivas de como as coisas estão se comportando de ponta a ponta. Isso é complicado mesmo em uma arquitetura simples. Considere um serviço que os clientes chamam por meio de um load balancer: o serviço fala com um cache remoto e um banco de dados remoto. Queremos que cada componente emita métricas sobre seu comportamento. Também queremos métricas sobre como cada componente percebe o comportamento de outros componentes. Quando as métricas de todas essas perspectivas são reunidas, o proprietário do serviço pode rastrear a fonte dos problemas rapidamente e procurar a causa.

Muitos serviços da AWS fornecem automaticamente informações operacionais sobre seus recursos. Por exemplo, o Amazon DynamoDB fornece métricas do Amazon CloudWatch sobre taxas de sucesso e erro e latência, conforme medido pelo serviço. No entanto, quando criamos sistemas que usam esses serviços, precisamos de muito mais visibilidade de como nossos sistemas estão se comportando. A instrumentação requer código explícito que registra quanto tempo as tarefas demoram, com que frequência certos caminhos de código são exercidos, metadados sobre o que a tarefa estava trabalhando e em quais partes as tarefas foram bem-sucedidas ou falharam. Se uma equipe não adicionar instrumentação explícita, ela será forçada a operar seu próprio serviço como uma caixa preta.

Por exemplo, se implementarmos uma operação da API de serviço que recuperou informações do produto por ID do produto, o código pode se parecer com o exemplo a seguir. Esse código procura informações do produto em um cache local, seguido por um cache remoto, seguido por um banco de dados:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // check our local cache
  ProductInfo info = localCache.get(request.getProductId());
  
  // check the remote cache if we didn't find it in the local cache
  if (info == null) {
    info = remoteCache.get(request.getProductId());
	
	localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    info = db.query(request.getProductId());
	
	localCache.put(info);
	remoteCache.put(info);
  }
  
  return info;
}

Se eu estivesse operando este serviço, precisaria de muita instrumentação neste código para poder entender seu comportamento na produção. Eu precisaria da capacidade de solucionar problemas de solicitações lentas ou com falha e monitorar tendências e sinais de que diferentes dependências estão em escala reduzida ou apresentando comportamento inadequado. Aqui está o mesmo código, anotado com algumas das perguntas que eu preciso responder sobre o sistema de produção como um todo ou sobre uma solicitação específica:

public GetProductInfoResponse getProductInfo(GetProductInfoRequest request) {

  // Which product are we looking up?
  // Who called the API? What product category is this in?

  // Did we find the item in the local cache?
  ProductInfo info = localCache.get(request.getProductId());
  
  if (info == null) {
    // Was the item in the remote cache?
    // How long did it take to read from the remote cache?
    // How long did it take to deserialize the object from the cache?
    info = remoteCache.get(request.getProductId());
	
    // How full is the local cache?
    localCache.put(info);
  }
  
  // finally check the database if we didn't have it in either cache
  if (info == null) {
    // How long did the database query take?
    // Did the query succeed? 
    // If it failed, is it because it timed out? Or was it an invalid query? Did we lose our database connection?
    // If it timed out, was our connection pool full? Did we fail to connect to the database? Or was it just slow to respond?
    info = db.query(request.getProductId());
	
    // How long did populating the caches take? 
    // Were they full and did they evict other items? 
    localCache.put(info);
    remoteCache.put(info);
  }
  
  // How big was this product info object? 
  return info;
}

O código para responder a todas essas perguntas (e mais) é um pouco maior que a lógica de negócios real. Algumas bibliotecas podem ajudar a reduzir a quantidade de código da instrumentação, mas o desenvolvedor ainda deve fazer perguntas sobre a visibilidade que as bibliotecas precisarão e, em seguida, o desenvolvedor deve ser intencional quanto à fiação na instrumentação.

Quando você soluciona problemas de uma solicitação que flui através de um sistema distribuído, pode ser difícil entender o que aconteceu se você apenas analisar essa solicitação com base em uma interação. Para montar o quebra-cabeça, achamos útil reunir em um só lugar todas as medidas de todos esses sistemas. Antes de podermos fazer isso, cada serviço deve ser instrumentado para registrar um ID de rastreamento para cada tarefa e propagar esse ID de rastreamento para outro serviço que colabora nessa tarefa. A coleta da instrumentação nos sistemas para um determinado ID de rastreamento pode ser feita após o fato, conforme necessário, ou quase em tempo real usando um serviço como o AWS X-Ray.

Detalhamento

A instrumentação permite a solução de problemas em vários níveis, desde olhar as métricas para verificar se existem anomalias sutis demais para acionar alarmes, até executar uma investigação para descobrir a causa dessas anomalias.

No nível mais alto, a instrumentação é agregada em métricas que podem acionar alarmes e ser exibidas nos painéis. Essas métricas agregadas permitem que os operadores monitorem a taxa geral de solicitações, a latência das chamadas de serviço e as taxas de erro. Esses alarmes e métricas nos informam sobre anomalias ou alterações que devem ser investigadas.

Depois de vermos uma anomalia, precisamos descobrir por que essa anomalia está acontecendo. Para responder a essa pergunta, contamos com métricas possibilitadas por ainda mais instrumentação. Ao instrumentar o tempo necessário para executar várias partes do atendimento de uma solicitação, podemos ver qual parte do processamento é mais lenta que o normal ou aciona erros com mais frequência.

Embora temporizadores e métricas agregados possam nos ajudar a descartar causas ou destacar uma área de investigação, eles nem sempre fornecem uma explicação completa. Por exemplo, podemos ser capazes de dizer pelas métricas que os erros são provenientes de uma operação específica da API, mas as métricas podem não revelar detalhes suficientes sobre o motivo pelo qual essa operação está falhando. Neste ponto, examinamos os dados brutos e detalhados do log emitidos pelo serviço para essa janela de tempo. Os logs brutos, em seguida, mostram a origem do problema: o erro específico que está acontecendo ou aspectos específicos da solicitação que estão desencadeando algum caso extremo.

Como instrumentamos

A instrumentação requer codificação. Isso significa que, quando estamos implementando novas funcionalidades, precisamos adicionar um tempo extra para indicar o que aconteceu, se houve êxito ou falha e quanto tempo levou. Como a instrumentação é uma tarefa de codificação tão comum, surgiram práticas na Amazon ao longo dos anos para abordar padrões comuns: padronização para bibliotecas de instrumentação comuns e padronização para relatórios métricos baseados em log estruturados.

A padronização das bibliotecas de instrumentação de métricas ajuda os autores das bibliotecas a dar visibilidade aos consumidores delas sobre como funcionam. Por exemplo, os clientes HTTP comumente usados se integram a essas bibliotecas comuns. Portanto, se uma equipe de serviço implementa uma chamada remota em outro serviço, eles obtêm instrumentação sobre essas chamadas automaticamente.

Quando um aplicativo instrumentado é executado e realiza trabalho, os dados de telemetria resultantes são gravados em um arquivo de log estruturado. Geralmente, esses dados são emitidos como uma entrada de log por "unidade de trabalho", seja uma solicitação para um serviço HTTP ou uma mensagem extraída de uma fila.

Na Amazon, as medições no aplicativo não são agregadas e ocasionalmente liberadas para um sistema de agregação de métricas. Todos os cronômetros e contadores de cada parte do trabalho são gravados em um arquivo de log. A partir daí, os logs são processados e as métricas agregadas são computadas após o fato por algum outro sistema. Dessa forma, terminamos com tudo, desde métricas operacionais agregadas de alto nível até dados detalhados de solução de problemas no nível de solicitação, tudo com uma única abordagem para instrumentar o código. Na Amazon, registramos em log primeiro e produzimos métricas agregadas posteriormente.

Instrumentação por meio de registro em log

Geralmente, instrumentamos nossos serviços para emitir dois tipos de dados de log: dados de solicitação e dados de depuração. Os dados do log de solicitação geralmente são representados como uma única entrada de log estruturada para cada unidade de trabalho. Esses dados contêm propriedades sobre a solicitação e o solicitante, a finalidade da solicitação, contadores de quantas vezes as coisas aconteceram e cronômetros de quanto tempo as coisas levaram. O log de solicitações serve como um log de auditoria e um rastreio para tudo o que aconteceu no serviço. Os dados de depuração incluem dados não estruturados ou pouco estruturados de quaisquer linhas de depuração que o aplicativo emita. Normalmente, essas são entradas de log não estruturadas, como erro Log4j ou linhas de log com aviso. Na Amazon, esses dois tipos de dados geralmente são emitidos em arquivos de log separados, parcialmente por motivos históricos, mas também porque pode ser conveniente fazer análise de logs em um formato de entrada homogêneo.

Agentes como o CloudWatch Logs Agent processam os dois tipos de dados de log em tempo real e os enviam para o CloudWatch Logs. Por sua vez, o CloudWatch Logs produz métricas agregadas sobre o serviço quase em tempo real. O Amazon CloudWatch Alarms lê essas métricas agregadas e aciona alarmes.

Embora possa ser caro registrar tantos detalhes sobre cada solicitação, na Amazon descobrimos que é incrivelmente importante fazer isso. Afinal, precisamos investigar blips de disponibilidade, picos de latência e problemas relatados pelos clientes. Sem registros detalhados, não podemos dar respostas aos clientes e não poderemos melhorar o serviço deles.  

Entrando nos detalhes

O tópico de monitoramento e alarmes é vasto. Neste artigo, não abordaremos tópicos como configuração e ajuste de limites de alarmes, organização de painéis operacionais, medição de performance do lado do servidor e do cliente, execução contínua de aplicativos "canários" e escolha do sistema certo para agregar métricas e analisar logs.

O foco deste artigo é a necessidade de instrumentar nossos aplicativos para produzir os dados de medição brutos corretos. Vamos descrever o que as equipes da Amazon se esforçam para incluir (ou evitar) ao instrumentar seus aplicativos.

Melhores práticas com logs de solicitações

Nesta seção, descreverei os bons hábitos que aprendemos ao longo do tempo na Amazon sobre o registro em log de nossos dados estruturados "por unidade de trabalho". Um log que atenda a esses critérios contém contadores que representam com que frequência as coisas acontecem, cronômetros que contêm quanto tempo as coisas levaram e propriedades que incluem metadados sobre cada unidade de trabalho.

Como registramos em log

Emita uma entrada de log de solicitação para cada unidade de trabalho. Normalmente, uma unidade de trabalho é uma solicitação que nosso serviço recebeu ou uma mensagem que ele extraiu de uma fila. Escrevemos uma entrada de log do serviço para cada solicitação que nosso serviço recebe. Não combinamos várias unidades de trabalho. Dessa forma, quando solucionamos problemas em uma solicitação com falha, temos uma única entrada de log para analisar. Essa entrada contém os parâmetros de entrada relevantes sobre a solicitação para ver o que ela estava tentando fazer, informações sobre quem era o chamador e todas as informações de tempo e contador em um único local.
Não emita mais de uma entrada de log de solicitação para determinada solicitação. Em uma implementação de serviço sem bloqueio, pode parecer conveniente emitir uma entrada de log separada para cada estágio em um pipeline de processamento. Em vez disso, temos mais sucesso na solução de problemas desses sistemas, conectando um identificador a um único "objeto de métricas" entre os estágios do pipeline e, em seguida, serializando as métricas como uma unidade após a conclusão de todos os estágios. Ter várias entradas de log por unidade de trabalho torna a análise de log mais difícil e aumenta a sobrecarga do registro em log (já caro) por um multiplicador. Se estivermos escrevendo um novo serviço sem bloqueio, tentamos planejar o ciclo de vida do registro de métricas em log antecipadamente, porque fica muito difícil refatorar e corrigir posteriormente.
Divida tarefas de longa duração em várias entradas de log. Em contraste com a recomendação anterior, se tivermos uma tarefa de fluxo de trabalho de longa duração, vários minutos ou várias horas, podemos decidir emitir uma entrada de log separada periodicamente para que possamos determinar se estão sendo feitos progressos ou onde está diminuindo a velocidade.
Registre detalhes sobre a solicitação antes de fazer coisas como validação. Achamos importante para a solução de problemas e o registro em log de auditoria registrar informações suficientes sobre a solicitação, para que possamos saber o que ela estava tentando realizar. Também achamos importante registrar essas informações o mais cedo possível, antes que a solicitação tenha a chance de ser rejeitada pela validação, autenticação ou lógica de limitação. Se estivermos registrando informações da solicitação recebida, limpamos a entrada (codificar, escapar e truncar) antes de registrá-las em log. Por exemplo, não queremos incluir strings longas de 1 MB em nossa entrada de log de serviço se o chamador aprovou uma. Fazer isso arriscaria encher nossos discos e nos custar mais do que o esperado no armazenamento de logs. Outro exemplo de higienização é filtrar caracteres de controle ASCII ou escapar sequências relevantes para o formato do log. Poderia ser confuso se o chamador aprovasse uma entrada própria do log de serviço e pudesse injetá-la em nossos logs. Consulte também: https://xkcd.com/327/
Planeje uma maneira de registrar em log com maior verbosidade. Para solucionar alguns tipos de problemas, o log não terá detalhes suficientes sobre solicitações problemáticas para descobrir por que elas falharam. Essas informações podem estar disponíveis no serviço, mas o volume de informações pode ser grande demais para justificar o registro em log o tempo todo. Pode ser útil ter um botão de configuração que você possa acionar para aumentar temporariamente a verbosidade do log enquanto investiga um problema. Você pode ativar o botão em hosts individuais, para clientes individuais ou a uma taxa de amostragem em toda a frota. É importante lembrar de desativar o botão quando terminar.
Mantenha os nomes das métricas curtos (mas não muito curtos). A Amazon usa a mesma serialização de logs de serviço há mais de 15 anos. Nessa serialização, cada nome de contador e timer é repetido em texto sem formatação em cada entrada do log de serviço. Para ajudar a minimizar a sobrecarga do registro em log, usamos nomes de cronômetro curtos, mas descritivos. A Amazon está começando a adotar novos formatos de serialização com base em um protocolo de serialização binário conhecido como Amazon Ion. Por fim, é importante escolher um formato que as ferramentas de análise de logs possam entender e que seja tão eficiente para serializar, desserializar e armazenar quanto possível.
Verifique se os volumes de log são grandes o suficiente para lidar com o registro em log no throughput máximo. Fazemos testes de carga dos nossos serviços com a máxima carga sustentada (ou até sobrecarga) durante horas. Precisamos garantir que, quando nosso serviço estiver lidando com excesso de tráfego, ele ainda tenha os recursos prontos para enviar logs com a taxa em que produzem novas entradas de log, ou os discos acabarão sendo preenchidos. Você também pode configurar o log para que ocorra em uma partição do sistema de arquivos diferente da partição raiz, para que o sistema não falhe devido ao excesso de registros em log. Discutimos outras atenuações para isso mais tarde, como o uso de amostragem dinâmica proporcional ao throughput, mas independentemente da estratégia, é essencial testar.
Considere o comportamento do sistema quando os discos estiverem cheios. Quando o disco de um servidor fica cheio, não é possível salvar os logs no disco. Quando isso acontece, um serviço deve parar de aceitar solicitações ou descartar logs e continuar operando sem monitoramento? A operação sem registro em log é arriscada, por isso testamos os sistemas para garantir que os servidores com discos quase cheios sejam detectados.
Sincronize os relógios. A noção de "horário" em sistemas distribuídos é notoriamente complicada. Não confiamos na sincronização do relógio em algoritmos distribuídos, mas é necessário para entender os logs. Executamos daemons como o Chrony ou o ntpd para sincronização do relógio e monitoramos servidores quanto ao desvio do relógio. Para facilitar, consulte o Amazon Time Sync Service.
Emita contagens zero para métricas de disponibilidade. A contagem de erros é útil, mas as porcentagens de erro também podem ser úteis. Para instrumentar uma métrica de "porcentagem de disponibilidade", uma estratégia que consideramos útil é emitir 1 quando a solicitação for bem-sucedida e 0 quando a solicitação falhar. Em seguida, a estatística "média" da métrica resultante é a taxa de disponibilidade. A emissão intencional de um ponto de dados 0 também pode ser útil em outras situações. Por exemplo, se um aplicativo executar a eleição do líder, emitir 1 periodicamente para quando um processo é o líder e 0 quando o processo não for o líder pode ser útil para monitorar a integridade dos seguidores. Dessa forma, se um processo parar de emitir um 0, é mais fácil saber que algo está com falha e não poderá assumir o comando se algo acontecer ao líder.

O que registramos em log

Registre a disponibilidade e a latência de todas as dependências. Achamos isso particularmente útil para responder às perguntas "por que a solicitação estava lenta?" ou "por que a solicitação falhou?". Sem esse log, podemos comparar apenas gráficos de dependências com gráficos de um serviço e adivinhar se um pico na latência de um serviço dependente levou à falha de uma solicitação que estamos investigando. Muitas estruturas de serviço e de cliente realizam métricas automaticamente, mas outras estruturas (como o AWS SDK, por exemplo) exigem instrumentação manual.
Divida as métricas de dependência por chamada, por recurso, por código de status etc. Se interagirmos com a mesma dependência várias vezes na mesma unidade de trabalho, incluiremos métricas sobre cada chamada separadamente e deixaremos claro com qual recurso cada solicitação estava interagindo. Por exemplo, ao chamar o Amazon DynamoDB, algumas equipes acharam útil incluir métricas de tempo e latência por tabela, código de erro e até mesmo o número de tentativas. Isso facilita a solução de problemas nos casos em que o serviço ficou lento devido a novas tentativas devido a falhas de verificação condicional. Essas métricas também revelaram casos em que o aumento da latência percebida pelo cliente era devido a tentativas de limitação ou paginação através de um conjunto de resultados e não por perda de pacotes ou latência da rede.
Registre as profundidades da fila de memória ao acessá-las. Se uma solicitação interage com uma fila e estamos extraindo um objeto dela, ou colocando algo nela, registramos a profundidade atual da fila no objeto de métricas enquanto estamos nele. Para filas na memória, essas informações são muito baratas de se obter. Para filas distribuídas, esses metadados podem estar disponíveis gratuitamente nas respostas às chamadas da API. Esse registro em log ajudará a encontrar backlogs em atraso e fontes de latência no futuro. Além disso, quando extraímos as coisas de uma fila, medimos o tempo que essas coisas passaram na fila. Isso significa que precisamos adicionar primeiro nossa própria métrica "tempo de enfileiramento" à mensagem antes de enfileirá-la.
Adicione um contador adicional para cada motivo de erro. Verifique se é possível adicionar um código que conte o motivo específico do erro para cada solicitação com falha. O log do aplicativo incluirá informações que levaram à falha e uma mensagem de exceção detalhada. No entanto, também achamos útil ver tendências por razões de erro nas métricas ao longo do tempo sem precisar buscar essas informações no log do aplicativo. É útil começar com uma métrica separada para cada classe de exceção de falha.
Organize erros por categoria de causa. Se todos os erros forem agrupados na mesma métrica, ela se tornará barulhenta e inútil. No mínimo, achamos importante separar os erros que eram "culpa do cliente" dos erros que eram "falha do servidor". Além disso, mais avarias podem ser úteis. Por exemplo, no DynamoDB, os clientes podem fazer solicitações de gravação condicional que retornam um erro se o item que eles estão modificando não corresponder às condições prévias na solicitação. Esses erros são deliberados e esperamos que ocorram ocasionalmente. Considerando que os erros de "solicitação inválida" dos clientes são provavelmente os erros que precisamos corrigir.
Registre metadados importantes sobre a unidade de trabalho. Em um log métrico estruturado, também incluímos metadados suficientes sobre a solicitação, para que possamos determinar posteriormente de quem era a solicitação e o que ela estava tentando fazer. Isso inclui os metadados que um cliente esperaria que tivéssemos em nosso registro quando eles alcançassem problemas. Por exemplo, o DynamoDB registra o nome da tabela com a qual uma solicitação está interagindo e os metadados, como se a operação de leitura era uma leitura consistente ou não. No entanto, ele não registra os dados que estão sendo armazenados ou recuperados do banco de dados.
Proteja os logs com controle de acesso e criptografia. Como os logs contêm algum grau de informações confidenciais, tomamos medidas para proteger esses dados e deixá-los seguros. Essas medidas incluem criptografar logs, restringir o acesso a operadores que estão solucionando problemas e basear regularmente esse acesso.
Evite colocar informações excessivamente sensíveis nos logs. Os logs precisam conter algumas informações confidenciais para serem úteis. Na Amazon, achamos importante que os logs incluam informações suficientes para saber de quem veio uma determinada solicitação, mas deixamos de fora informações excessivamente sensíveis, como parâmetros de solicitação que não afetam o roteamento ou o comportamento do processamento da solicitação. Por exemplo, se o código estiver analisando uma mensagem do cliente e essa análise falhar, é importante não registrar a carga útil para proteger a privacidade do cliente, por mais difícil que possa ser a resolução de problemas posteriormente. Usamos ferramentas para tomar decisões sobre o que pode ser registrado de maneira opt-in em vez de opt-out, para impedir o registro em log de um novo parâmetro sensível adicionado posteriormente. Serviços como o Amazon API Gateway permitem configurar quais dados serão incluídos em seu log de acesso, o que funciona como um bom mecanismo de aceitação.
Registre um ID de rastreamento e propague-o nas chamadas de back-end. Uma determinada solicitação do cliente provavelmente envolverá muitos serviços trabalhando em cooperação. Pode ser apenas dois ou três serviços para muitas solicitações da AWS, para muito mais serviços para solicitações da amazon.com. Para entender o que aconteceu quando solucionamos problemas de um sistema distribuído, propagamos o mesmo ID de rastreamento entre esses sistemas, para podermos alinhar logs de vários sistemas para ver onde as falhas ocorreram. Um ID de rastreamento é um tipo de ID de meta solicitação que é carimbado em uma unidade de trabalho distribuída pelo serviço "front door" que foi o ponto de partida para a unidade de trabalho. O AWS X-Ray é um serviço que ajuda ao fornecer parte dessa propagação. Achamos importante passar o rastreio para nossa dependência. Em um ambiente multithread, é muito difícil e propenso a erros para a estrutura fazer essa propagação em nosso nome. Por isso adquirimos o hábito de transmitir IDs de rastreamento e outros conteúdos da solicitação (como um objeto de métrica!) em nossas assinaturas de método. Também achamos útil repassar um objeto Context em nossas assinaturas de métodos, para que não tenhamos que refatorar quando encontrarmos um padrão semelhante para repassar no futuro. Para as equipes da AWS, não se trata apenas de solucionar problemas de nossos sistemas, mas também de clientes que solucionam problemas deles. Os clientes confiam nos rastreamentos do AWS X-Ray sendo transmitidos entre os serviços da AWS quando interagem entre si em nome do cliente. Ele exige que propaguemos os IDs de rastreamento do AWS X-Ray do cliente entre os serviços para que eles possam obter dados completos de rastreamento.
Registre em log métricas de latências diferentes, dependendo do código e tamanho do status. Os erros geralmente são rápidos, como acesso negado, limitação e respostas de erro de validação. Se os clientes começarem a ficar limitados a uma taxa alta, isso poderá fazer com que a latência pareça enganosamente boa. Para evitar essa poluição de métrica, registramos um cronômetro separado para obter respostas bem-sucedidas e focamos nessa métrica em nossos painéis e alarmes, em vez de usar uma métrica de tempo genérica. Da mesma forma, se houver uma operação que possa ser mais lenta, dependendo do tamanho da entrada ou do tamanho da resposta, consideramos emitir uma métrica de latência categorizada, como SmallRequestLatency e LargeRequestLatency. Além disso, garantimos que nossas solicitações e respostas sejam adequadamente delimitadas para evitar modos complexos de interrupção e interrupção, mas mesmo em um serviço cuidadosamente projetado, essa técnica de medição de métricas pode isolar o comportamento do cliente e manter o ruído que distrai os painéis.

Melhores práticas do log de aplicativos

Esta seção descreve os bons hábitos que aprendemos na Amazon sobre o registro em log de dados de depuração não estruturados.

Mantenha o registro do aplicativo livre de spam. Embora possamos ter instruções de log no nível INFO e DEBUG no caminho da solicitação para ajudar no desenvolvimento e depuração em ambientes de teste, consideramos desabilitar esses níveis de log na produção. Em vez de confiar no log do aplicativo para obter informações de rastreamento de solicitação, pensamos no log de serviço como um local para as informações de rastreamento que podemos produzir facilmente métricas e ver tendências agregadas ao longo do tempo. No entanto, não há regra em preto e branco aqui. Nossa abordagem é revisar continuamente nossos logs para verificar se são muito barulhentos (ou não suficientemente barulhentos) e ajustar os níveis de log ao longo do tempo. Por exemplo, quando fazemos mergulho em log, geralmente encontramos instruções de registro muito barulhentas ou métricas que desejamos ter. Felizmente, essas melhorias geralmente são fáceis de fazer, por isso adquirimos o hábito de arquivar itens de backlog de acompanhamento rápido para manter nossos registros limpos.
Inclua o ID da solicitação correspondente. Quando estamos solucionando um erro no log do aplicativo, geralmente queremos ver detalhes sobre a solicitação ou o chamador que acionou o erro. Se os dois logs contiverem o mesmo ID de solicitação, podemos facilmente saltar de um registro para o outro. As bibliotecas de registro em log do aplicativo gravam o ID da solicitação correspondente, se configurado corretamente, e a ID da solicitação é definida como um ThreadLocal. Se um aplicativo for multithread, considere tomar cuidado especial para definir o ID da solicitação correta quando um encadeamento começar a trabalhar em uma nova solicitação.
Limite a taxa de spam de erros no log de um aplicativo. Normalmente, um serviço não emitirá muito para o log do aplicativo, mas se repentinamente começar a exibir um grande volume de erros, poderá repentinamente começar a gravar uma alta taxa de entradas de log muito grandes com rastreios de pilha. Uma maneira de descobrirmos isso é limitar a taxa com que frequência um determinado criador de logs registrará.
Prefira strings de formato em vez de String#format ou concatenação de strings. As operações mais antigas da API de log de aplicativos aceitam uma única mensagem de string em vez da API de string de formato varargs do log4j2. Se o código for instrumentado com instruções DEBUG, mas a produção estiver configurada no nível de ERRO, é possível desperdiçar o trabalho formatando as strings de mensagens DEBUG que são ignoradas. Algumas operações da API de registro em log oferecem suporte à passagem de objetos arbitrários que terão seus métodos toString() chamados apenas se a entrada do log for gravada.
IDs de solicitação de log de chamadas de serviço com falha. Se um serviço é chamado e retorna um erro, o serviço provavelmente retornou um ID de solicitação. Consideramos útil incluir o ID da solicitação em nosso log para que, se precisarmos acompanhar o proprietário do serviço, tenhamos uma maneira de encontrar facilmente suas próprias entradas correspondentes no log de serviço. Erros de tempo limite tornam isso complicado, porque o serviço talvez ainda não tenha retornado um ID de solicitação ou uma biblioteca-cliente talvez não o tenha analisado. No entanto, se tivermos um ID de solicitação de volta do serviço, nós o registramos.

Melhores práticas para serviços de alto throughput

Para a grande maioria dos serviços da Amazon, o logon em todas as solicitações não impõe uma sobrecarga de custo irracional. Serviços de throughput mais elevado entram em uma área mais cinzenta, mas geralmente ainda fazemos logon em todas as solicitações. Por exemplo, é natural supor que o DynamoDB, atendendo a um pico superior a 20 milhões de solicitações por segundo do tráfego interno da Amazon, não registre muito, mas, na verdade, registra todas as solicitações de solução de problemas e por motivos de auditoria e conformidade. Aqui estão algumas dicas de alto nível que usamos na Amazon para tornar o registro em log mais eficiente com maior throughput por host:

Amostragem de log. Em vez de escrever todas as entradas, considere escrever todas as N entradas. Cada entrada também inclui quantas entradas foram ignoradas para que os sistemas de agregação de métricas possam estimar o volume real do log nas métricas calculadas. Outros algoritmos de amostragem, como a amostragem de reservatório, fornecem amostras mais representativas. Outros algoritmos priorizam erros de registro em log ou solicitações lentas em vez de solicitações rápidas e bem-sucedidas. No entanto, com a amostragem, perde-se a capacidade de ajudar os clientes e solucionar problemas específicos. Alguns requisitos de conformidade o proíbem completamente.
Descarregue a serialização e a descarga de logs em um thread separado. Essa é uma mudança fácil e é comumente usada.
Rotação frequente de logs. A rotação de arquivos de log a cada hora pode parecer conveniente, para que você tenha menos arquivos, mas girando a cada minuto, várias coisas melhoram. Por exemplo, o agente que lê e compacta o arquivo de log estará lendo o arquivo do cache da página em vez do disco, e a CPU e o IO dos arquivos de compactação e envio serão espalhados ao longo da hora, em vez de sempre serem acionados no final do hora.
Grave logs pré-compactados. Se um agente de expedição de logs compactar logs antes de enviá-los para um serviço de arquivamento, a CPU e o disco do sistema dispararão periodicamente. É possível amortizar esse custo e reduzir a E / S do disco pela metade, transmitindo os logs compactados para o disco. Isso vem com alguns riscos embora. Consideramos útil usar um algoritmo de compactação que pode lidar com arquivos truncados no caso de uma falha no aplicativo.
Grave em um ramdisk/tmpfs. Pode ser mais fácil para um serviço gravar logs na memória até que eles sejam enviados para fora do servidor em vez de gravar os logs no disco. Em nossa experiência, isso funciona melhor com a rotação de logs a cada minuto e a rotação de logs a cada hora.
Agregados na memória. Se for necessário gerenciar centenas de milhares de transações por segundo em uma única máquina, pode ser muito caro gravar uma única entrada de log por solicitação. No entanto, você perde muita observância ignorando isso, portanto, achamos útil não otimizar prematuramente.
Monitorar a utilização de recursos. Prestamos atenção ao quão perto estamos de atingir algum limite de escala. Medimos nossa IO e CPU por servidor e quanto desses recursos estão sendo consumidos pelos agentes de registro em log. Quando realizamos testes de carga, os executamos por tempo suficiente para que possamos provar que nossos agentes de expedição de logs podem acompanhar nosso throughput.

Tenha as ferramentas de análise de log corretas

Na Amazon, operamos os serviços que escrevemos, portanto, todos precisamos nos tornar especialistas na solução de problemas. Isso inclui ser capaz de fazer análises de log sem esforço. Existem muitas ferramentas à nossa disposição, desde a análise local de logs para analisar um número relativamente pequeno de logs, até a análise distribuída de logs para filtrar e agregar resultados de um enorme volume de logs.

Consideramos importante investir nas ferramentas e nos runbooks das equipes para análise de logs. Se os logs são pequenos agora, mas um serviço espera crescer com o tempo, prestamos atenção quando nossas ferramentas atuais param de ser dimensionadas, para que possamos investir na adoção de uma solução distribuída de análise de logs.

Análise de log local

O processo de análise de log pode exigir experiência em vários utilitários de linha de comando do Linux. Por exemplo, um "encontre os principais endereços IP do locutor no log" é simplesmente:

cat log | grep -P "^RemoteIp=" | cut -d= -f2 | sort | uniq -c | sort -nr | head -n20

No entanto, existem várias outras ferramentas úteis para responder perguntas mais complexas com nossos registros, incluindo:

• jq: https://stedolan.github.io/jq/
• RecordStream: https://github.com/benbernard/RecordStream

Análise de log distribuído

Qualquer serviço de análise de big data pode ser usado para fazer análises de logs distribuídos (por exemplo, Amazon EMR, Amazon Athena, Amazon Aurora e Amazon Redshift). No entanto, alguns serviços vêm equipados com sistemas de registro em log, por exemplo, Amazon CloudWatch Logs.

Insights do CloudWatch Logs
• AWS X-Ray: https://aws.amazon.com/xray/
• Amazon Athena: https://aws.amazon.com/athena/

Conclusão

Como proprietário de um serviço e desenvolvedor de software, passo uma quantidade enorme de tempo analisando as saídas da instrumentação - gráficos em painéis, arquivos de log individuais - e usando ferramentas de análise de log distribuídas, como o CloudWatch Logs Insights. Estas são algumas das minhas coisas favoritas a fazer. Quando preciso de uma pausa depois de concluir uma tarefa desafiadora, recarrego minhas baterias e me recompô com um mergulho no tronco. Começo com perguntas como "por que essa métrica aumentou aqui?" Ou "a latência dessa operação pode ser menor?". Quando minhas perguntas levam a um beco sem saída, costumo descobrir algumas medidas que seriam úteis no código, então adiciono a instrumentação, teste e envio uma revisão de código aos meus colegas de equipe.

Apesar de muitas métricas virem com os serviços gerenciados que usamos, precisamos dedicar muito tempo a instrumentar nossos próprios serviços, a fim de termos a visibilidade necessária para operá-los de maneira eficaz. Durante os eventos operacionais, precisamos determinar rapidamente por que estamos com um problema e o que podemos fazer para atenuar esse problema. Ter as métricas corretas em nossos painéis é crucial para que possamos fazer esse diagnóstico rapidamente. Além disso, como estamos sempre alterando nossos serviços, adicionando novos recursos e mudando a maneira como eles interagem com suas dependências, o exercício de atualizar e adicionar a instrumentação correta está sempre em andamento.

• “Look at your data”, do ex-Amazonian John Rauser: https://www.youtube.com/watch?v=coNDCIMH8bk (aos 13:22 ele literalmente imprime os logs para estudá-los melhor)
• “Investigating anomalies” do ex-Amazonian John Rauser: https://www.youtube.com/watch?v=-3dw09N5_Aw
• “How humans see data” do ex-Amazonian John Rauser: https://www.youtube.com/watch?v=fSgEeI2Xpdc
https://www.akamai.com/uk/en/about/news/press/2017-press/akamai-releases-spring-2017-state-of-online-retail-performance-report.jsp


Sobre o autor

David Yanacek é o engenheiro-chefe sênior responsável pelo AWS Lambda. David trabalha como desenvolvedor de software na Amazon desde 2006, e anteriormente trabalhou no Amazon DynamoDB e no AWS IoT, além de em estruturas de trabalho internas de web service e sistemas de automação de operações de frota. Uma das atividades preferidas de David é a análise de logs e o exame de métricas operacionais para descobrir maneiras de tornar a execução de sistemas mais eficientes com o passar do tempo.

Como usar o descarte de carga para evitar sobrecarga Como evitar backlogs de fila intransponíveis