Medindo experimentos de performance com o Scientist

Publicado por Thiago von Sydow no dia dev

Science

Recentemente estávamos com um problema de performance em um ponto crítico no RD Station, um código que executa uma busca específica no ElasticSearch. Após investigar encontramos um ponto de melhoria simples, mas uma dúvida surgiu: como medir a performance desta alteração garantindo o mesmo resultado de forma fácil e segura?

Eu estava procurando uma oportunidade para testar a gem scientist criada pelo GitHub e este problema pareceu um ótimo candidato.

O conceito usado na gem é bem simples, você configura o código atual (chamado de controle), uma ou mais versões novas a serem testadas (chamadas de candidatos) e para onde enviar as métricas. As métricas enviadas pelo Scientist atualmente são apenas tempo de execução que o código levou, mas em um futuro pode trazer consumo de memória e outros.

Definido qual o trecho de código seria alterado foi criado um experimento, uma classe simples que inclui o módulo Scientist::Experiment, veja abaixo:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
class FilterPercolatorExperiment
  include Scientist::Experiment

  def initialize(manager_id)
    @name = 'filter-percolator'
    @manager_id = manager_id
  end

  def enabled?
    RolloutControl.has_access?('filter-percolator', @manager_id)
  end

  def publish(result)
    LibratoWrapper.timing "science.#{@name}.control", result.control.duration
    LibratoWrapper.timing "science.#{@name}.candidate", result.candidates.first.duration

    store_mismatch_data(result) if result.mismatched?
  end

  def store_mismatch_data(result)
    payload = {
      name: name,
      context: context,
      control: observation_payload(result.control),
      candidate: observation_payload(result.candidates.first),
      execution_order: result.observations.map(&:name)
    }

    Rails.logger.info("[FilterPercolatorExperiment::Mismatch] - #{payload.inspect}")
  end

end

Explicando os métodos:

  • enabled?: Este método é utilizado para saber se tanto o controle quanto o candidato serão executados. É importante pensar quando ele será habilitado porque serão executadas ambas versões e isso irá impactar a sua performance. Neste caso utilizamos uma FeatureToggle e habilitamos apenas para algumas contas selecionadas.

  • publish: Após executar ambas as versões, este método é chamado para que você publique seus resultados onde desejar. Neste caso o tempo de execução está indo para o Librato, onde montamos um gráfico para analisar.

  • store_mismatch_data: Se o resultado do nosso candidato foi diferente do controle (verificado através do método result.mismatched?) adicionamos um log para verificar qual foi a diferença.

Para executar o experimento basta instanciar, configurar a execução dos códigos e chamar o método run:

1
2
3
4
5
6
experiment = FilterPercolatorExperiment.new(manager_id)

experiment.use { percolate_elastic_lists } #código atual (controle)
experiment.try { filtered_percolate_elastic_lists } #código novo (candidato)

experiment.run

Ao executar o método run o retorno sempre será o do código de controle. Qualquer erro que ocorra no candidato será colocado no log que configuramos e não interferirá na execução atual (o que é extremamente importante).

Vamos ver os resultados?

Métricas do resultado

Analisando o gráfico, podemos ver que o candidato está de 2 a 3 vezes mais rápido. Não foram gerados logs com divergência de dados, então nosso novo código se provou correto e mais performático!

Recomendamos o Scientist para refactors em pontos críticos ou para testar otimizações de performance. Ele dá uma segurança adicional aos seus testes automatizados e é divertido ver os gráficos dos seus experimentos!

Não deixe de conferir também o post Criando experimentos com a gema Split para ver como ralizar testes A/B com seus usuários de forma fácil.

Gostou? Quer saber algo mais ou tirar uma dúvida? Deixe seu comentário :wink:

Referências

Thiago von Sydow

Thiago von Sydow

Full Stack Developer

Comentários