Tutorial: Distributed Tracing com Spring

Veja o texto com dicas do Software Architect da Netshoes para implementar este tipo de padrão

O problema

A arquitetura de microserviços é, atualmente, o direcionamento para a arquitetura de novos sistemas. Esse fato traz diversos benefícios já mapeados, como: fácil escalabilidade, atingimento facilitado do time-to-market através de deploys contínuos, etc. Entretanto, originam-se novos problemas e/ou desafios que devem ser levados em consideração ao iniciar um projeto com microserviços. Em sistemas monolíticos, era possível rastrear toda a atividade de um determinado input, seja ele um request de um serviço HTTP/SOAP, os dados de início de um job ou o consumo de mensagens de determinada fila.

Normalmente essas atividades eram realizadas por meio de um log bem escrito, ou até através de dados persistidos em tabelas de auditoria/log. Esse mecanismo era o suficiente, dado que haviam poucas integrações e poucas instâncias em produção — apenas as necessárias para garantir a disponibilidade da aplicação caso uma máquina pare de responder ou durante um evento deploy. Já com a arquitetura orientada a microserviços, se tem um maior número de integrações entre aplicações. Essas podem, inclusive, ser de diferentes tecnologias (como Java, .Net e Python), além de a armazenar a informação em diferentes estruturas — como bases SQL, NoSQL ou em arquivos.

Distributed Tracing

O padrão Distributed Tracing soluciona esse problema ao criar um identificador único no request inicial e repassá-lo para todas as demais requisições. O identificador deve ser exibido em todas as mensagens de log e, além disso, deve ser possível enviar data e hora de início e fim de requests para um serviço centralizador.

É fortemente recomendado utilizar o Distributed Tracing em conjunto com o padrão Log Aggregator, porém este último não será explorado nesse artigo.

Spring Cloud Sleuth

Esse framework implementa o padrão Distributed Tracing de forma transparente para diversas bibliotecas do ecossistema Spring. Ele é fortemente baseado em Dapper, Zipkin e HTrace. O foco desse artigo é versão 1.3.4 do framework.

Terminologia

O framework se baseia na terminologia do artigo Dapper, que define Span e Trace.

• Span: Menor unidade de trabalho, ele é um identificador de 64 bits. Os Spans são relacionados uns aos outros por meio de um outro identificador de 64 bits, denominado Trace. Um Span também contém outros dados como descrição, anotações, id do Span original e um id do processo. É obrigatório que um Span iniciado seja finalizado para que sua duração também seja armazenada. As anotações mencionadas anteriormente são utilizadas para marcar um evento. Exemplos: client send e server received.
• Trace: Representa o fluxo desde a primeira requisição até a última, ele é composto de um ou mais Spans.

Funcionamento

Considerando o desenho a seguir, tem-se dois microserviços que expõem serviços REST. Um dos microserviços é responsável pelos serviços de usuário e o outro microserviço é responsável pela validação de CPF.

Quando o endpoint de criação do usuário é chamado, ele delega para o microserviço de validação de CPF a tarefa de verificar se o documento é válido. Nesse cenário, são criados um TraceId e um SpanId no endpoint de criação do cliente. Quando o serviço de validação de CPF é chamado, o TraceId e o SpanId são repassados para esse serviço e, ao receber esses dados, o serviço de validação de CPF cria um novo SpanId, relacionado ao TraceId e ao SpanId anterior. Durante esse processo também são adicionados eventos de Client Send, Server Received, Client Received e Server Sent aos Spans.

Log correlation

Automaticamente o framework adiciona o nome da aplicação, o traceId e spanId aos logs da aplicação, além de um quarto parâmetro que indica se o log foi exportado para o Zipkin ou não, falaremos dele mais adiante. Segue um exemplo do resultado:

service1.log:2016–02–26 11:15:47.561 INFO [service1,2485ec27856c56f4,2485ec27856c56f4,true] 68058 - - [nio-8081-exec-1] i.s.c.sleuth.docs.service1.Application : Hello from service1. Calling service2
service2.log:2016–02–26 11:15:47.710 INFO [service2,2485ec27856c56f4,9aa10ee6fbde75fa,true] 68059 - - [nio-8082-exec-1] i.s.c.sleuth.docs.service2.Application : Hello from service2. Calling service3 and then service4
service3.log:2016–02–26 11:15:47.895 INFO [service3,2485ec27856c56f4,1210be13194bfe5,true] 68060 - - [nio-8083-exec-1] i.s.c.sleuth.docs.service3.Application : Hello from service3
service2.log:2016–02–26 11:15:47.924 INFO [service2,2485ec27856c56f4,9aa10ee6fbde75fa,true] 68059 - - [nio-8082-exec-1] i.s.c.sleuth.docs.service2.Application : Got response from service3 [Hello from service3]
service4.log:2016–02–26 11:15:48.134 INFO [service4,2485ec27856c56f4,1b1845262ffba49d,true] 68061 - - [nio-8084-exec-1] i.s.c.sleuth.docs.service4.Application : Hello from service4
service2.log:2016–02–26 11:15:48.156 INFO [service2,2485ec27856c56f4,9aa10ee6fbde75fa,true] 68059 - - [nio-8082-exec-1] i.s.c.sleuth.docs.service2.Application : Got response from service4 [Hello from service4]
service1.log:2016–02–26 11:15:48.182 INFO [service1,2485ec27856c56f4,2485ec27856c56f4,true] 68058 - - [nio-8081-exec-1] i.s.c.sleuth.docs.service1.Application : Got response from service2 [Hello from service2, response from service3 [Hello from service3] and from service4 [Hello from service4]]

Note que os dados de evento e de duração dos Spans não são apresentados no log. Esses dados podem ser enviados para o Zipkin.

Zipkin

É um sistema de armazenamento de Distributed Tracing e também foi construído baseado na terminologia do artigo Dapper. Ele possui uma interface para consulta dos traces, na qual é possível filtrar por traces específicos e até visualizar stacks dos erros.

Essa integração é opcional e não é necessário enviar a totalidade dos dados, apenas uma amostra.

Exemplo de consulta de um trace de sucesso:

Exemplo de consulta de um trace com erros:

Ao clicar em um Span que possui erros, o detalhamento abaixo é exibido:

Instrumentações suportadas

Todas as instrumentações abaixo são habilitadas automaticamente quando o Spring Cloud Sleuth está no classpath da aplicação:

• Runnable e Callable
• Hystrix
• RxJava
• Spring MVC
• Async Servet
• Rest Template
• Feign
• Traverson
• Métodos anotados com @Async
• Métodos anotados com @Scheduled
• Executor, ExecutorService and ScheduledExecutorService
• Zuul
• Spring Cloud Function
• Mensageria somente através do spring-integration ou spring-cloud-stream

A instrumentação das bibliotecas spring-kafka e spring-rabbit não são suportadas nativamente pelo framework na versão 1.3.4. Felizmente, para o spring-rabbit, pode-se utilizar a biblioteca spring-cloud-sleuth-amqp criada pela Netshoes. A biblioteca faz uso de AOP para realizar essa instrumentação. Há também um starter disponível chamado: spring-cloud-sleuth-amqp-starter.

Implementação

Cenário

Implementação do spring-cloud-sleuth em um ecossistema de dois microserviços, os quais são:

• user: Responsável pelo cadastro do usuário através REST.
• notification: Responsável por notificar o usuário por e-mail através de REST ou RabbitMQ

Caso de uso

Quando o usuário se cadastrar — devemos enviar um e-mail com a senha inicial.

Codificação

Para fins didáticos não será listado nesse artigo todo o código fonte das aplicações. O código completo pode ser encontrado em https://github.com/netshoes/sample-sleuth-users e em https://github.com/netshoes/sample-sleuth-notification. Neste local também é possível também encontrar informações sobre como iniciar a aplicação, instalar o Zipkin e maiores detalhes.

Dependency Management

Supondo que a aplicação já exista, será necessário adicionar no pom.xml dentro do bloco de dependencyManagement a dependência abaixo:

<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-dependencies</artifactId>
<version>Edgware.SR3</version>
<type>pom</type>
<scope>import</scope>
</dependency>

Log correlation

Como o framework funciona por instrumentação, basta adicionar a dependência do spring-cloud-starter-sleuth dentro do bloco de dependencies do pom.xml:

<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-sleuth</artifactId>
</dependency>

Essa biblioteca vai habilitar todas as instrumentações já citadas, porém é necessário tomar alguns cuidados, como por exemplo: não instanciar um RestTemplate diretamente — ele deve ser declarado com um @Bean para que o framework gerencie o objeto.

Também é necessário declarar no application.properties o nome da aplicação através da propriedade spring.application.name. Por exemplo:

spring.application.name=users

Segue abaixo um exemplo da saída dos logs das aplicações para o POST no endpoint de cadastramento de usuário:

2018–04–26 16:58:26.829 INFO [users,3a94cde6bc08efc7,3a94cde6bc08efc7,false] 64898 - - [nio-8080-exec-1] c.n.sample.sleuth.user.Application: User morris.jakubowski@test.com created.
2018–04–26 16:58:27.011 INFO [notification,3a94cde6bc08efc7,c08a162838f4f8c1,false] 64838 - - [nio-8081-exec-1] c.n.s.sleuth.notification.Application: Notification sent to morris.jakubowski@test.com
2018–04–26 16:58:27.026 INFO [users,3a94cde6bc08efc7,3a94cde6bc08efc7,false] 64898 - - [nio-8080-exec-1] c.n.sample.sleuth.user.Application: Notification about initial password sent to morris.jakubowski@test.com

No log acima o mesmo traceId 3a94cde6bc08efc7 é apresentado em todas as mensagens, o que indica que se refere ao mesmo trace (começando na aplicação users, passando pelo notification e finalizando novamente no users). Dois diferentes spanIds foram criados, um para o users e outro para o notification.

Zipkin via http

Para habilitar o envio de dados para o Zipkin, devemos declarar a dependência spring-cloud-starter-zipkin:

<dependency>
<groupId>org.springframework.cloud</groupId>
<artifactId>spring-cloud-starter-zipkin</artifactId>
</dependency>

E também configurar a propriedade spring.zipkin.baseUrl, por exemplo:

spring.zipkin.baseUrl=http://localhost:9090

O valor padrão para essa propriedade é http://localhost:9411. Logo abaixo podemos ver os traces da comunicação entre as aplicações no Zipkin:

Ao clicar no span, detalhes são exibidos, como: tempo de resposta e horário dos eventos. É importante notar que essas informações não são exibidas no log.

Por padrão, somente 10% das requisições são enviadas para o Zipkin. Esse valor pode ser alterado configurando a propriedade spring.sleuth.sampler.percentage, com valores entre 0.0 e 1.0. Para aumentar esse valor para 50% basta configurar:

spring.sleuth.sampler.percentage=0.5

Essa propriedade deve ser configurada na aplicação que cria o trace, pois é nesse momento que esse dado será utilizado. As demais aplicações do fluxo vão seguir apenas a definição da aplicação anterior: isso evita que um trace seja enviado parcialmente. Lembre-se que é possível saber se um trace foi enviado para o Zipkin apenas olhando o log:

2018–04–26 16:58:26.829 INFO [users,3a94cde6bc08efc7,3a94cde6bc08efc7,false] 64898 - - [nio-8080-exec-1] c.n.sample.sleuth.user.Application: User morris.jakubowski@test.com created.
2018–04–26 17:22:40.123 INFO [users,4394add6bc08efc9,2240cdecfc08eab0,true] 64900 - - [nio-8080-exec-1] c.n.sample.sleuth.user.Application: User morris.jakubowski@test.com created.

O Zipkin possui um mecanismo de storage para os traces — por padrão ele utiliza um InMemoryStorage, o qual não é recomendado para uso em ambiente produtivo. Além do armazenamento in memory, também são suportados: Cassandra, MySQL e Elastic Search.

Um outro componente importante é o collector: o Zipkin possui collector para Kafka, Subscribe e HTTP. Nesse artigo será utilizado o HTTP.

O spring-cloud-sleuth não irá indisponibilizar ou causar lentidão na aplicação caso o Zipkin não responda, mesmo com o collector de http.

Outros frameworks para Java:

• OpenTracing
• DropWizardZipkin
• HTraceZipkin

Leituras relacionadas:

• Pattern: Log aggregation
• Pattern: Exception tracking
• Zipkin — Quickstart
• Zipkin — Existing instrumentations

Referências:

• Dapper, a Large-Scale Distributed Systems Tracing Infrastructure
• OpenTrancing.io
• Pattern: Distributed tracing
• Spring Cloud Sleuth
• Spring Cloud Sleuth — Doc
• Zipkin
• Zipkin — Github

Entre para nosso time