A partir do momento que iniciamos a utilização de aplicações distribuídas em produção, como por exemplo em soluções com microserviços, alguns desafios começam a surgir, um deles é como coletar informações das comunicações entre as aplicações distribuídas, onde suas comunicações são remotas.

As comunicações entre as aplicações podem ser feitas de diferentes formas: REST, SOAP, Mensageria, entre outras e como medir o tempo de execução das comunicações? Como saber quais aplicações são envolvidas nas comunicações? Falando de chamadas REST é possível saber o tempo de resquest e response, porém e se tiver outras aplicações envolvidas? Principalmente falando de microserviços as comunicações entre aplicações podem requisitar outras aplicações dificultado a medição e até mesmo o “debuging” das comunicações. Baseado nesse cenário, há o conceito de tracing distribuído para lidar com esse desafio.

Tracing distribuído

O conceito de tracing distribuído seria basicamente a abordagem de rastreamento entre todas as chamadas/aplicações envolvidas em uma requisição, ou seja, como identificar e medir os tempos de serviços envolvidos para executar uma determinada ação, por exemplo: Um serviço A é requisitado por uma aplicação, porém esse serviço A depende de outros dois serviços, B e C, assim, o tempo de retorno do serviço A é a soma de tempo da execução de A + B + C.

Dado uma solução distribuída, como identificar o tempo de execução de cada um dos serviços independentes? Como descobrir qual do serviços tem maior tempo de retorno? Para isso, vamos precisar de alguma ferramenta para realizar o tracing distribuído, a qual precisa identificar cada chamada dos serviços possibilitando o rastreamento individual de cada chamada e posteriormente permitindo uma visão geral de todos serviços envolvidos na requisição inicial.

Spring Cloud Sleuth

Dentro do projeto Spring Cloud tem o subprojeto Sleuth, que é um framework para tracing distribuído baseado na termologia do Google Dapper e HTrace, o qual faz a geração de identificadores paras as comunicações distribuídas, possibilitando análises individuais e agrupadas a partir de uma aplicação origem.

O Sleuth basicamente adiciona identificadores chamados de trace e span ids em cada log, onde o trace id é o identificador único entre todas as chamadas e o span id é o identificado individual de cada chamada. Assim, para cada log gerado, o Sleuth adiciona 4 informações dentro de colchetes no log como demostrado na imagem abaixo.

INFO [trips,477eaea44387aa18,477eaea44387aa18,true] 1 --- [nio-8080-exec-1] br.com.emmanuelneri.TripController      : get trip
INFO [tickets,477eaea44387aa18,561458440a91a130,true] 1 --- [nio-8090-exec-1] br.com.emmanuelneri.TicketsController : get tickets
INFO [accommodations,477eaea44387aa18,a51b594e8b7a5131,true] 1 --- [nio-8070-exec-1] b.c.e.AccommodationsController : get accommodations

Baseado nos logs acima, as informações são:

• O primeiro parâmetro é nome da aplicação que gerou o log;
• O Segundo parâmetro é o trace id, no caso da imagem acima todos são iguais porque estão pertecem ao mesmo contexto;
• O terceiro parâmetro é o span id, cada requisição nas aplicações gera um novo id;
• O quarto parâmetro indica se o log será sincronizado para alguma ferramenta, que dependendo da configuração nem todos os logs serão enviados.

Dessa forma, o Sleuth gera esses identificadores para que possam ser visualizadas em alguma ferramenta de agrupamento como o Zipkin.

Zipkin

O Zipkin é uma solução para interpretação de logs distribuídos com objetivo de realizar o troubleshoot de latência em aplicações distribuídas, onde apresenta uma interface gráfica que permite a visualização do trancing entre as aplicações. O Zipkin também é baseado na termologia do Google Dapper.

Utilizando Spring Cloud Sleuth e Sleuth em projetos Spring Boot

Vamos começar pela inicialização do Zipkin, o qual podemos subir através de uma imagem docker.

docker run -itd \
    --name trace \
    -p 9411:9411 \
    openzipkin/zipkin

Observação: No modo padrão da imagem openzipkin/zipkin, todas as análises e logs recebidos serão armazenados em memória, com isso, é apenas um modo para testes, para utilizar em produção podem ser utilizados outros modos com Cassandra, Mysql, Elasticsearch, entre outros.

Nas aplicações Spring Boot, as quais vão gerar os logs, é necessário adicionar duas dependências: spring-cloud-starter-sleuth para iniciar a geração dos identificadores nos logs e spring-cloud-sleuth-zipkin para enviar os logs para o Zipkin.

    org.springframework.cloud
    spring-cloud-starter-sleuth
    Finchley.SR1


    org.springframework.cloud
    spring-cloud-sleuth-zipkin
    Finchley.SR1

Observação: Utilizando a dependência spring-cloud-sleuth-zipkin os dados serão enviados para o Zipkin via HTTP, caso seja necesário mudar para utilizar uma solução de fila, como Rabbit, Kafka, etc, basta utilizar a dependência spring-cloud-sleuth-stream.

Há duas configurações após adicionar as dependências, informar a url do Zipkin na property spring.zipkin.base-url e alterar o percentual de log enviado para o Zipkin na property spring.sleuth.sampler.probability onde o padrão é enviar apenas 10% do log gerado e vamos alterar para enviar 100% dos logs gerados pelas aplicações para facilitar nosso cenário de testes.

spring.zipkin.base-url=http://localhost:9411
spring.sleuth.sampler.probability=1.0

Observação: Nas versões mais antigas o percentual de envio usava a propriedade pring.sleuth.sampler.percentage, após a versão 2 mudou para probability.

Por fim, precisamos definir a estratégia de geração dos identificadores pelo Sleuth, no caso vamos definir um bean com a estratégia AlwaysSampler, onde sempre será gerado identificadores no logs da aplicações.

@Bean
public AlwaysSampler defaultSampler() {
    return new AlwaysSampler();
}

Feito isso, as aplicações estão configuradas para gerar identificadores nas requisições e enviar os dados para o Zipkin, basta apenas adicionar os logs nos serviços desejados para iniciar o tracing dos serviços.

@RestController
@RequestMapping("/trips")
public class TripController {

   private Logger logger = LoggerFactory.getLogger(TripController.class);

    @GetMapping
    public String getTrip() {
        logger.info("Hello trip");
        return "Hello trip";
    }

}

Observação: Uma alternativa para não precisar adicionar log em todos as partes do código é alterar o nível do log das servlets (logging.level.org.springframework.web.servlet.DispatcherServlet=DEBUG) ou implementar um interceptor para todas chamadas de endpoints, porém, o trade off dessas soluções são a grande quantidade de logs que serão produzidos com todos os serviços.

Exemplo

Exemplificando a utilização do Sleuth e Zipkin para realizar o tracing distribuído, vamos criar três aplicações: trips, tickets e accommodations, onde a aplicação trips consulta as aplicações tickets e accommodations para retornar as passagens e acomodações para uma viagem, como ilustrado na imagem abaixo. Assim, com esse cenário, simulamos um contexto de uma aplicação que possui dependência de outras aplicações e podemos visualizar o tracing dos serviços no Zipkin.

Quando realizado uma requisição no serviço trips, que irá consultar as aplicações tickets e accommodations, obtemos todo trace do serviço trips com base nos identificadores do Sleuth, que proporcionam informações como: aplicações e endpoints envolvidos, tempo de execução em cada aplicação e tempo total em uma visão de timeline, como demonstrando na imagem abaixo retirada do dashboard do Zipkin.

O código fonte do exemplo está disponível no github.

Conclusão

Concluindo, para lidar com o desafio de comunicações distribuídas em microservices as soluções do Spring Cloud Sleuth e Zipkin são uma boa alternativa para analisar as dependências e debugar os tempos de requisições entre aplicações, onde o Sleuth fica responsável pela geração dos identificadores e o Zipkin possibilita uma visão centralizadas das requisições entre as aplicações distribuídas.