A gravação de logs é uma ferramenta muito importante para o desenvolvedor, mas ao criar sistemas distribuídos, ela se torna uma pedra fundamental que deve ser incorporada diretamente à base do seu aplicativo. Caso contrário, a complexidade do desenvolvimento de microsserviços rapidamente se tornará evidente.
O .Net Core 3 trouxe uma excelente , por isso, se suas aplicações utilizam chamadas HTTP diretas para interação entre serviços, você pode aproveitar essa funcionalidade padrão. No entanto, se a arquitetura do seu backend prevê a interação por meio de um broker de mensagens (RabbitMQ, Kafka, etc.), você ainda precisará se preocupar em transmitir o contexto de correlação por meio dessas mensagens de forma independente.
Neste artigo, vamos pegar um simples aplicativo de API da web e organizar a gravação de logs que irá
manter a correlação de ponta a ponta entre os logs de serviços independentes, permitindo que você visualize facilmente todas as atividades que foram geradas por uma solicitação específica do cliente
ter um ponto de entrada unificado com uma análise conveniente, de forma que a ferramenta de log possa ser utilizada até mesmo pelo Suporte, que recebe perguntas como "tive um erro no meu aplicativo com este ID de solicitação"
Primeiro, precisamos decidir sobre o provedor de logging em nossa aplicação. O principal requisito para um logging moderno é a estrutura, ou seja, devemos trabalhar não com mensagens de texto simples, mas com objetos. Com esses logs, podemos facilmente construir representações de nossas mensagens em diferentes perspectivas e realizar análises.
Para nossa aplicação, vamos utilizar o pacote Serilog, que possui um excelente suporte para logging estrutural e um rico sistema de extensões. Vou omitir as etapas básicas de configuração (você pode encontrar uma grande quantidade de artigos sobre este assunto) e presumir que
o Serilog já está configurado e é o logger padrão do seu provedor de injeção de dependência,
com a configuração incluindo o enriquecimento das mensagens com propriedades de contexto (Enrich.FromLogContext)
O próximo passo é escolher para qual sistema de coleta centralizada de logs enviar as mensagens do Serilog. Provavelmente, a opção mais comum entre as soluções de código aberto hoje é a pilha ELK (Elasticsearch, Logstash e Kibana), e a utilizaremos. Para isso, vamos aproveitar a oferta da — após o registro no plano gratuito, teremos em mãos todo o poder do mecanismo de busca Lucene.
Só nos resta adicionar ao nosso projeto o pacote
Install-Package Serilog.Sinks.Logzio
E adicionar o respectivo enricher na configuração do nosso logger, fornecendo o token de acesso
LoggerConfiguration loggerConfig = new LoggerConfiguration();
loggerConfig.WriteTo.Logzio(secrets.LogzioToken, 10, TimeSpan.FromSeconds(10), null, LogEventLevel.Debug);
Ao rodar o aplicativo, poderemos observar nossas mensagens não apenas no console, mas também no Kibana.
Interfaces
Em um aplicativo de tipo serviço, podemos destacar duas principais interfaces de interação com o mundo externo, que chamaremos de interface vertical e horizontal. A interface vertical é a API web, através da qual chegam as chamadas do aplicativo cliente. A interface horizontal é o broker de mensagens, utilizado para troca de dados com outros serviços internos.
Vamos considerar as etapas de implementação da correlação em cada uma dessas interfaces.
Correlação em requisições HTTP
Para obter o máximo de informações, precisamos gerar um identificador de correlação o mais próximo possível do início da atividade, ou seja, no gateway ou diretamente no cliente (móvel ou web). Como estamos lidando hoje com um aplicativo backend, simplesmente indicaremos a exigência do cabeçalho "X-Correlation-ID" em todas as requisições à API web.
Adicione o pacote , cuja função é capturar o valor do cabeçalho que precisamos.
Install-Package CorrelationID
Vamos adicioná-lo ao pipeline de processamento da requisição.
public class Startup
{
public void Configure(IApplicationBuilder application)
{
application
.UseCorrelationId(new CorrelationIdOptions
{
Header = "X-Correlation-ID",
IncludeInResponse = false,
UpdateTraceIdentifier = false,
UseGuidForCorrelationId = false
});
}
}
Agora, com isso, vamos fazer um filtro de ação simples:
classe pública selada ApiRequestFilter : ActionFilterAttribute
{
public ApiRequestFilter(IApiRequestTracker apiRequestTracker, ICorrelationContextAccessor correlationContextAccessor)
{
_correlationContextAccessor = correlationContextAccessor ?? throw new ArgumentNullException(nameof(correlationContextAccessor));
}
private readonly ICorrelationContextAccessor _correlationContextAccessor;
public override async Task OnActionExecutionAsync(ActionExecutingContext context, ActionExecutionDelegate next)
{
if (!Guid.TryParse(_correlationContextAccessor.CorrelationContext.CorrelationId, out Guid correlationId))
{
context.Result = new BadRequestResult();
return;
}
await next.Invoke();
}
public override async Task OnResultExecutionAsync(ResultExecutingContext context, ResultExecutionDelegate next)
{
await next.Invoke();
}
}
E vamos adicioná-lo ao controlador
[Route("[controller]")]
[ApiController]
[ServiceFilter(typeof(ApiRequestFilter))]
public class CarsController : ControllerBase
{
}
Como resultado, o controlador começará a retornar 400 Bad request para todas as solicitações sem o cabeçalho correspondente contendo o identificador.
Depois que começamos a receber o identificador do cliente, devemos adicioná-lo ao contexto de registro, faremos isso com uma camada envolvente:
public class CorrelationIdContextLogger
{
public CorrelationIdContextLogger(RequestDelegate next)
{
_next = next ?? throw new ArgumentNullException(nameof(next));
}
readonly RequestDelegate _next;
public async Task InvokeAsync(HttpContext httpContext, ILogger logger, ICorrelationContextAccessor correlationContextAccessor)
{
if (Guid.TryParse(correlationContextAccessor.CorrelationContext.CorrelationId, out Guid correlationId))
{
using (logger.BeginScopeWith(("CorrelationId", correlationId)))
{
await _next(context);
}
}
else
{
await _next(context);
}
}
}
Em nosso aplicativo, usamos o ILogger padrão do pacote Microsoft.Extensions.Logging.Abstractions, portanto, vamos adicionar o valor com uma simples extensão a ele.
public static IDisposable BeginScopeWith(this ILogger logger, params (string key, object value)[] keys)
{
return logger.BeginScope(keys.ToDictionary(x => x.key, x => x.value));
}
Adicionamos a camada no pipeline de processamento de solicitações e obtemos o resultado desejado.
public class Startup
{
public void Configure(IApplicationBuilder application)
{
application.UseMiddleware();
}
}
Agora, todas as atividades originadas por solicitações à nossa API web contêm o identificador de correlação, o que facilita sua associação.
Correlação nas mensagens do broker
O próximo passo é estabelecer a transmissão e recepção do identificador de correlação através de um broker de mensagens. No nosso exemplo, vamos utilizar o RabbitMQ e, como cliente, vamos escolher o framework MassTransit. Novamente, vamos pular a configuração inicial do MassTransit e ir direto para a configuração de logging.
Para começar, podemos ativar os logs do próprio MassTransit, para isso, adicionamos ao nosso aplicativo o pacote
Install-Package MassTransit.SerilogIntegration
Agora, após adicionar o logger às configurações do MassTransit, poderemos ver os logs do framework.
services
.AddSingleton(provider =>
{
return Bus.Factory.CreateUsingRabbitMq(cfg =>
{
cfg.UseSerilog();
});
});
Vamos fazer com que nosso aplicativo, como resposta a uma requisição POST, envie um evento SomethingDoneMessage com o valor "done". O contrato de tal mensagem pode ser descrito assim:
namespace MbMessages
{
public interface ISomethingDoneMessageV1
{
string Value { get; }
}
}
As mensagens do MassTransit são essencialmente um envelope, onde mensagens do broker estão encapsuladas. O envelope se parece mais ou menos assim:
{
"messageId": "59020000-5dba-0015-10b8-08d77ec28593",
"requestId": "59020000-5dba-0015-5674-08d77ec28592",
"conversationId": "59020000-5dba-0015-bca8-08d77ec28594",
"destinationAddress": "rabbitmq://bear.rmq.cloudamqp.com/aelzlsta/ya.servicetemplate.receiveendpoint",
"headers": {},
"messageType": [
"urn:message:MbMessages:ISomethingDoneMessageV1"
],
"message": {
"value": "done"
}
}
Na mensagem, podemos ver campos de controle, que são necessários para o funcionamento do próprio framework, mas também temos a possibilidade de adicionar propriedades adicionais a este envelope. Além disso, o MassTransit possui recursos integrados para trabalhar com alguns campos opcionais, dos quais nos interesa mais o identificador de correlação CorrelationId.
Vamos adicionar à interface do contrato da mensagem a interface CorrelatedBy:
namespace MbMessages
{
public interface ISomethingDoneMessageV1 : CorrelatedBy
{
string Value { get; }
}
}
Vamos implementá-la e atribuir o valor à propriedade CorrelationId ao criar a mensagem:
internal class SomethingDoneMessageV1 : ISomethingDoneMessageV1
{
internal SomethingDoneMessageV1(Guid correlationId, string value)
{
CorrelationId = correlationId;
Value = value;
}
public Guid CorrelationId { get; private set; }
public string Value { get; private set; }
}
Se olharmos a mensagem atualizada, veremos que o identificador de correlação se tornou não apenas parte da nossa mensagem, mas também parte do envelope — esse identificador agora também será utilizado em todos os logs do MassTransit, o que significa que será muito mais fácil resolver problemas a nível de corretor de mensagens.
{
"messageId": "59020000-5dba-0015-10b8-08d77ec28593",
"requestId": "59020000-5dba-0015-5674-08d77ec28592",
"conversationId": "59020000-5dba-0015-bca8-08d77ec28594",
"correlationId": "c7ff562a-b639-415b-9add-c9e524a727cc",
"destinationAddress": "rabbitmq://bear.rmq.cloudamqp.com/aelzlsta/ya.servicetemplate.receiveendpoint",
"headers": {},
"messageType": [
"urn:message:MbMessages:ISomethingDoneMessageV1"
],
"message": {
"correlationId": "c7ff562a-b639-415b-9add-c9e524a727cc",
"value": "Hello"
}
}
Resta-nos configurar o registro dessas propriedades auxiliares da mensagem, para isso adicionaremos ao projeto o pacote . O pacote adiciona um filtro ao pipeline de processamento de mensagens do MassTransit, que empilha o contexto da mensagem em uma pilha segura para threads. O Serilog lê o contexto da pilha e adiciona essas propriedades extras aos nossos objetos de log.
Install-Package Serilog.Enrichers.MassTransitMessage
No MassTransit, inserimos o filtro
services
.AddSingleton(provider =>
{
return Bus.Factory.CreateUsingRabbitMq(cfg =>
{
cfg.UseSerilog();
cfg.UseSerilogMessagePropertiesEnricher();
});
});
E na configuração do Serilog, adicionamos o enriquecedor
Log.Logger = new LoggerConfiguration()
.Enrich.FromMassTransitMessage()
.CreateLogger();
Como a aplicação que recebe a mensagem da fila RabbitMQ tem acesso a todas as propriedades do envelope do MassTransit, podemos usar o identificador de correlação obtido dentro da aplicação consumidora, assim como passá-lo adiante em toda a cadeia de chamadas.
Como resultado, nossos logs passaram a conter o CorrelationId não apenas dentro de um único serviço, mas também ao interagir com outras aplicações.
Assim, o sistema de registro obtido em aplicações .Net nos permite correlacionar logs de microssérvios absolutamente diferentes — mesmo aqueles que operam através de um corretor de mensagens. E com o Elasticsearch, podemos rapidamente e facilmente analisar logs, construindo os dashboards necessários no Kibana (um exemplo é mostrado na imagem do post).
Claro, em sua forma atual, o registro não cobrirá as interações complexas entre seus serviços e vários sistemas externos, mas implementar essa organização desde o início do desenvolvimento do projeto é uma daquelas coisas pelas quais você mesmo agradecerá mais de uma vez.
Você pode examinar o código fonte do sistema resultante no projeto:
Fonte: habr.com
