O que o APM responde e os logs não

Dois cursos atrás você tinha logs estruturados, depois traces. Os dois respondem perguntas sobre uma coisa que aconteceu. Nenhum responde a pergunta que te fazem primeiro, que é alguma versão de "o site está bem?"

Um milhão de linhas de log não responde isso sem agregação, e agregar um milhão de linhas por minuto não é para o que um armazenamento de logs serve. Métricas são: números, em intervalos, pequenos o bastante para guardar para sempre e baratos o bastante para consultar a cada atualização de painel.

Application Performance Monitoring (APM) é métrica com uma opinião no formato do Rails. Ele sabe o que é uma ação de controller, o que parece um N+1 e o que significa "a requisição média", então a visão padrão dele é sobre a sua aplicação e não sobre a sua CPU.

flowchart LR
  M["Métricas / APM: tem algo errado, mais ou menos onde, e quão grave?"] --> T["Traces: onde exatamente, numa requisição"]
  T --> L["Logs: o que aconteceu, com quais valores"]
  L -.->|"a correção"| C["Código"]
  M -.->|"alertas"| P["Uma pessoa"]

As três perguntas que o APM responde

Está saudável agora? Taxa de erro, vazão e latência, atualizadas a cada poucos segundos, contra ontem e contra a semana passada.

O que é lento, em agregado? Não "esta requisição foi lenta" (traces fazem isso), mas "este endpoint é a coisa mais lenta que servimos, e ele é 40% do nosso tempo total". Esse ranking é o que transforma trabalho de desempenho de palpite em fila.

A mudança ajudou? Uma marca de deploy num gráfico de latência, com um antes e um depois. Sem isso, "parece mais rápido" é toda a evidência disponível.

De onde vêm os números

O Rails emite eventos de instrumentação para tudo com que um APM se importa, e todo agente de APM para Rails é construído sobre o mesmo mecanismo que você pode usar diretamente:

ActiveSupport::Notifications.subscribe("process_action.action_controller") do |event|
  # event.payload carrega :controller, :action, :status,
  #                      :view_runtime, :db_runtime, :path, :method
  StatsD.timing("request.duration", event.duration,
                tags: ["controller:#{event.payload[:controller]}",
                       "action:#{event.payload[:action]}",
                       "status:#{event.payload[:status]}"])
end

Isso é bem perto do que um APM faz, e não uma ilustração simplificada. Os eventos são documentados, e os que importam são poucos:

Leve duas coisas dessa tabela além dos nomes.

O process_action.action_controller carrega :view_runtime e :db_runtime separados, o que significa que a divisão entre tempo de renderização e tempo de banco está disponível sem nenhum tracing. Essa razão única responde a pergunta de que a aula 2 do curso de Puma precisava (esta aplicação é limitada por I/O ou por CPU) a partir de dados que o Rails já emite.

E o cache_read.active_support carrega :hit, então a sua taxa de acerto de cache é uma métrica que você pode ter hoje, e não algo que você supõe.

Prefira tempo monotônico

Um bloco de um argumento, como o de cima, recebe um Event cuja duration já vem do relógio monotônico. A armadilha é a forma de cinco argumentos, em que start e finish são objetos Time de relógio de parede, a menos que você peça outra coisa:

ActiveSupport::Notifications.monotonic_subscribe("sql.active_record") do |name, start, finish, id, payload|
  # aqui start e finish são floats monotônicos, não objetos Time
end

Um relógio de parede pode se mover: o NTP o ajusta, e ele pode andar para trás. Isso produz durações negativas ou absurdas, numa taxa baixa o bastante para ser descartada como ruído e alta o bastante para distorcer um percentil. O tempo monotônico só anda para frente, e para medir durações é o instrumento correto.

O que o APM não é

• Não é um profiler. Ele diz que um endpoint é lento, não qual linha de Ruby está quente. Isso é outra ferramenta com outro custo.
• Não substitui traces. Agregados escondem a requisição individual; você precisa dos dois, e é por isso que o curso anterior existe.
• Não é de graça. Preço por host ou por requisição, e uma conta de cardinalidade que se comporta como a do curso de logs.

O que este curso cobre

1. O que o APM responde e os logs não (esta aula).
2. As métricas que valem a pena.
3. Percentis, médias e Apdex.
4. Instrumentando esta aplicação.
5. Alertas em que as pessoas agem.
6. Escolhendo e pagando por uma ferramenta.
7. Juntando tudo: uma configuração de monitoramento.

Pontos-chave

• Métricas respondem "o sistema está saudável?", que logs e traces não respondem sem uma agregação para a qual não foram feitos.
• APM é métrica que entende Rails: ações de controller, consultas, views, jobs e cache.
• O ActiveSupport::Notifications é o mecanismo que todo agente usa, e você pode assiná-lo diretamente.
• O process_action.action_controller já separa :view_runtime de :db_runtime, e o cache_read.active_support carrega :hit.
• O event.duration de um assinante de um argumento já é monotônico; na forma de cinco argumentos, use monotonic_subscribe, porque o relógio de parede pode andar para trás.