Análise de desempenho de aplicações Java usando o Metrics

O que é o Metrics?

O Metrics é um framework que provê formas de avaliar o comportamento de componentes críticos do sistema. Ele faz isso através de estatísticas que apontam para os pontos problemáticos da aplicação facilitando assim o diagnóstico de comportamentos indesejáveis, principalmente relacionados à performance. Para coletar essas estatísticas é necessário que sejam informados os componentes que serão monitorados na aplicação e isso é feito através de Anotações. Resumindo, para usar o Metrics você precisa apenas anotar os componentes que serão monitorados e exibir as estatísticas geradas para algum canal (console, arquivo, ...), e com uma periodicidade (e.g. hora, minuto, ...).

Arquitetura

Agora que você entendeu o que o Metric faz, é interessante descrever a sua arquitetura peculiar. Da forma que ele foi projetado, os usuários têm a flexibilidade de customizar métricas conforme desejado para o projeto e também integrar o Metrics à ferramentas conhecidas (e.g. Log4j, Jersey, Ehcache) através do uso de seus módulos.

Conceitos-chave

As estatísticas do Metrics são geradas em tempo de execução, por isso é necessário que o escopo de análise tenha as suas métricas centralizadas em algum lugar. Para isso, existe o componente MetricRegistry, que é um objeto que encapsula as métricas configuradas para a aplicação. Sempre que for necessário acessá-las (e.g. geração de relatórios), basta acessar esse objeto, que deve ser um Singleton para garantir que haja apenas uma instância do registro de métricas na aplicação garantindo assim a consistência das métricas obtidas.

Para armazenar as métricas da aplicação, o MetricRegistry possui um método de  registro. Dessa forma, para que uma métrica seja armazenada, é necessário invocar o método de registro. Isso garante que durante a execução da aplicação seja possível ter uma visão em tempo real das métricas coletadas.

Componentes

O Metrics gira em torno do seu módulo core, que contém os componentes conceituais de extração de estatísticas. Vamos descrevê-los aqui, para que você saiba o que é possível fazer com cada um deles.

Meter

Essa métrica obtém o número de chamadas a um método e também a média delas no ciclo de vida do objeto. Para que seja possível contar as ocorrências é necessário chamar o método mark para registrar a contagem. Dessa forma, cada vez que o método é chamado, será contabilizada uma marcação que servirá para calcular a frequência de acesso ao método monitorado.

Na prática se você quiser garantir que um método seja monitorado com essa métrica, basta escrever algo como:

1
2
3
4
5
6
7
8
@EnableMetrics
class MeterMetric {
    [...]
 @Metered(name = "metodo")
 public void metodo() {
  // Implementação do método
 }
}

No trecho acima foi utilizado o Metrics for Spring para que seja possível utilizar anotações como forma de registrar as métricas. A anotação @EnableMetrics habilita o registro da métrica Meter, que foi anotada no método com @Metered. Essa anotação garante que a métrica seja registrada no repositório centralizado de métricas com o name definido para esse método e que sejam contabilizadas as marcações a cada chamada ao método.

A resposta obtida nesse monitoramento durante a execução de uma aplicação seria algo como o ilustrado abaixo:

1
2
3
4
5
6
7
8
9
25/06/18 18:21:39 ==============================================================

-- Meters ----------------------------------------------------------------------
com.condessalovelace.refmetrics.MeterMetric.metodo
             count = 1
         mean rate = 0,21 events/second
     1-minute rate = 0,00 events/second
     5-minute rate = 0,00 events/second
    15-minute rate = 0,00 events/second

Os dados exibidos acima significam que o método foi chamado 1 vez (count = 1), com uma frequência de acesso de 0,21 vezes a cada segundo.

Gauge

O objetivo dessa métrica é retornar um valor específico. Esse valor por algum motivo precisa ser monitorado, por isso, a forma ideal de logá-lo é usando essa métrica. Existem implementações de Gauges que podem ser usadas para propósitos específicos, mas nesse post vou mostrar um exemplo de Gauge customizado para uma aplicação Java:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
// Gauge customizado
@Component
@EnableMetrics
class GaugeMetric implements Gauge<Integer> {

 @Override
 public Integer getValue() {
  return Thread.activeCount();
 }
}

// Utilização e registro do gauge
@Autowired
@Metric(name = "threads", absolute = true)
private GaugeMetric gaugeMetric;

O trecho acima cria um Gauge para monitorar o número de threads ativas na aplicação. Esse Gauge é registrado como métrica através da anotação @Metric, que recebe um nome que pode ser absoluto ou o nome completo da classe concatenado ao nome dado.

A resposta obtida nesse monitoramento durante a execução de uma aplicação seria algo como o ilustrado abaixo:

1
2
3
4
5
25/06/18 18:07:58 ==============================================================

-- Gauges ----------------------------------------------------------------------
threads
             value = 3

O relatório informa que foram encontradas 3 threads em execução quando a métrica foi coletada.

Histrograma

Histrogramas medem a distribuição de valores numa cadeia de dados. É uma medida interessante para saber como fluem os dados na aplicação, por exemplo, os retornados por uma consulta ao banco de dados. O exemplo abaixo mostra como seria feita essa configuração:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
// DAO que irá atualizar o histograma
@Component
@EnableMetrics
class HistogramDAO {
 @Autowired
 private MetricRegistry metricRegistry;

 public Integer buscarDados(int size) {
  metricRegistry.getHistograms().get(name(HistogramDAO.class, "result-size")).update(size);
  // Implementação do método
 }
}

// Registro do histograma que seria feito no contexto de um singleton
metricRegistry.histogram(name(HistogramDAO.class, "result-size"));

// Recuperação do histograma e seus dados
metricRegistry.getHistograms().get(name(HistogramDAO.class, "result-size")).getSnapshot();

Foi utilizado o método histogram para registrar a classe HistogramDAO e o método update para atualizar a contagem de registros retornados pelo método buscarDados (para fins didáticos, esse número é parâmetro do método). Como resultado da análise, seria exibido o seguinte log:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
26/06/18 10:06:40 ==============================================================

-- Histograms ------------------------------------------------------------------
com.condessalovelace.refmetrics.HistogramDAO.result-size
             count = 2
               min = 3
               max = 5
              mean = 3,96
            stddev = 1,00
            median = 3,00
              75% <= 5,00
              95% <= 5,00
              98% <= 5,00
              99% <= 5,00
            99.9% <= 5,00

O relatório informa que foram realizadas 2 chamadas ao método anotado, com uma média de aproximadamente 4 resultados retornados, e nos últimos 5 min durante a maior parte do tempo (75% - 99,9%) foram retornados aproximadamente 5 resultados.
Nota: A forma de utilizar histogramas não é muito madura, mesmo com mecanismos de injeção de dependências observei que é necessário adicionar programaticamente a atualização do histograma. Uma forma de contornar isso é criar um Interceptor para adicionar a chamada ao método update do histograma. Assim haveria menos poluição no método a ser instrumentado. 

Timers

O Timer é basicamente um Meter das chamadas ao recurso e um Histograma da duração das mesmas. Basicamente, usando o Timer você estaria englobando todas as métricas do metrics-core e por isso ele costuma ser mais usado. Então, para utilizar um Timer é necessário apenas anotá-lo e registrá-lo como métrica. Para isso, vamos usar a anotação @Timed do Codehale:

1
2
3
4
5
6
7
// Classe que irá ser observada
class TimerDAO {
 @Timed
 public void buscar(long time) {
  // Implementação da busca
 }
}

Pronto, só é necessário anotar o método com o @Timed e o gatilho de inicialização e de término do monitoramento será disparado no contexto do corpo do método anotado, sem a necessidade de dispará-lo programaticamente pelos métodos start e stop do Timer. O log do resultado da análise seria:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
26/06/18 10:30:23 ==============================================================

-- Timers ----------------------------------------------------------------------
com.condessalovelace.refmetrics.TimerDAO.buscar
             count = 1
         mean rate = 0,13 calls/second
     1-minute rate = 0,00 calls/second
     5-minute rate = 0,00 calls/second
    15-minute rate = 0,00 calls/second
               min = 5047,88 milliseconds
               max = 5047,88 milliseconds
              mean = 5047,88 milliseconds
            stddev = 0,00 milliseconds
            median = 5047,88 milliseconds
              75% <= 5047,88 milliseconds
              95% <= 5047,88 milliseconds
              98% <= 5047,88 milliseconds
              99% <= 5047,88 milliseconds
            99.9% <= 5047,88 milliseconds

Observe que o Timer exibe as métricas de um Meter e de um Histograma, como foi explicado anteriormente. Com esse componente é possível enxergar a frequência de acesso a um recurso ao longo da execução da aplicação (0,13 chamadas por segundo) e o tempo médio de obtenção dos dados que o recurso provê (aproximadamente 5 segundos). Por isso, esse componente é excelente para depurar problemas de performance numa aplicação.
Nota: Devido a uma limitação do Spring AOP, apenas métodos public podem ser anotados com o @Timed. Se você tentar anotar um método private ou protected, a métrica não será registrada e não será logado o problema em nível INFO. Além disso, observei que se o método anotado for invocado por AOP, o counter não contabiliza a invocação. Aí é necessário chamar o start e o stop do Timer programaticamente.

Relatórios

As métricas registradas no registro único precisam ser visíveis e uma forma de alcançar isso é gerando relatórios. O Metrics possui suporte a diferentes estratégias de geração de relatório, que são agendados de acordo com a periodicidade desejada. Para ilustrar como usar esses relatórios, vou utilizar o Spring for Metrics como forma de injetar esse relatório e não precisar registrá-lo explicitamente. Isso será feito utilizando o componente MetricsConfigurerAdapter do Ryantenney. Esse componente possui um método de registro de relatórios onde será possível registrar todos os relatórios que a aplicação irá gerar. A implementação seria algo como o trecho abaixo:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
@Configuration
@EnableMetrics
public class ReportController extends MetricsConfigurerAdapter {

 @Override
 public void configureReporters(MetricRegistry metricRegistry) {
  registerReporter(ConsoleReporter.forRegistry(metricRegistry).build()).start(1, TimeUnit.SECONDS);
  registerReporter(Slf4jReporter.forRegistry(metricRegistry).build()).start(1, TimeUnit.SECONDS);
 }
}

As anotações @Configuration e @EnableMetrics são usadas em conjunto para injetar o componente que representa o relatório e suas métricas. A classe herda do MetricsConfigurerAdapter para que implemente o método configureReporters e assim registre todos os relatórios desejados pela aplicação. Nesse caso, estão sendo registrados relatórios para o Console e para o Log4j.
Nota: O log exposto na explanação sobre os componentes é o log gerado pelo relatório do Console.

Conclusão

Esse post demonstrou na prática e de forma sucinta como você pode usar o Metrics para analisar o desempenho de aplicações Java. Com o que foi apresentado aqui, espero que você seja capaz de instrumentar as suas aplicações para extrair o melhor desempenho delas.

Referências

Comentários

Postagens mais visitadas deste blog

Configurando um projeto Java no GitHub com Travis e SonarLint

Manipulando arquivos XML em Java