Rejestrowanie jest niezwykle ważnym narzędziem dla programistów, ale podczas tworzenia systemów rozproszonych staje się to fundamentem, który należy wbudować w podstawy aplikacji, w przeciwnym razie złożoność rozwoju mikroserwisów bardzo szybko zacznie dawać o sobie znać.
W .Net Core 3 dodano świetną , więc jeśli Twoje aplikacje korzystają z bezpośrednich wywołań HTTP do interakcji między serwisami, możesz skorzystać z tej wbudowanej funkcjonalności. Jednak, jeśli architektura Twojego backendu zakłada interakcję przez broker wiadomości (RabbitMQ, Kafka itp.), wciąż musisz zająć się przekazywaniem kontekstu korelacji przez te wiadomości samodzielnie.
W tym artykule weźmiemy proste aplikacje web API i zorganizujemy rejestrowanie, które
zachowa pełną korelację między logami niezależnych serwisów, aby można było łatwo zobaczyć wszystkie działania, które zostały wywołane przez konkretne żądanie z klienta
mieć jednolity punkt wejścia z wygodną analizą, aby narzędzie do rejestrowania mogło być używane nawet przez Dział Wsparcia, który otrzymuje pytania typu „w mojej aplikacji wystąpił błąd z takim a takim identyfikatorem żądania”
Po pierwsze, musimy zdecydować się na dostawcę rejestrowania w naszej aplikacji. Główne wymaganie wobec nowoczesnego rejestrowania to strukturalność, tzn. musimy pracować nie z płaskimi wiadomościami tekstowymi, a z obiektami. Dzięki takim logom możemy łatwo budować przedstawienia naszych wiadomości w różnych perspektywach i prowadzić analizy.
Dla naszej aplikacji skorzystamy z pakietu Serilog, który ma doskonałe wsparcie dla strukturalnego rejestrowania i bogaty system rozszerzeń. Pominę podstawowe etapy jego konfiguracji (możesz znaleźć wiele artykułów na ten temat) i założę, że
Serilog jest już skonfigurowany i jest domyślnym rejestratorem w Twoim dostawcy wstrzykiwania zależności
w jego konfiguracji włączono wzbogacanie wiadomości właściwościami kontekstu (Enrich.FromLogContext)
Kolejnym krokiem jest wybranie, do jakiego systemu centralnego zbierania logów chcemy wysyłać wiadomości z Serilog. Najpowszechniejszym obecnie rozwiązaniem w otwartym oprogramowaniu jest stos ELK (Elasticsearch, Logstash i Kibana), którego użyjemy. W tym celu skorzystamy z oferty od — po zarejestrowaniu się na darmowym planie mamy w rękach pełną moc silnika wyszukiwania Lucene.
Pozostaje nam dodać do naszego projektu pakiet
Install-Package Serilog.Sinks.Logzio
I dodać odpowiedni wzbogacacz do konfiguracji naszego loggera, podając mu token dostępu
LoggerConfiguration loggerConfig = new LoggerConfiguration();
loggerConfig.WriteTo.Logzio(secrets.LogzioToken, 10, TimeSpan.FromSeconds(10), null, LogEventLevel.Debug);
Uruchamiając aplikację, będziemy mogli obserwować nasze wiadomości nie tylko w konsoli, ale także w Kibanie.
Interfejsy
W aplikacji typu serwisowego można wyróżnić dwa główne interfejsy jej interakcji z otoczeniem: oznaczymy je jako interfejs pionowy i poziomy. Interfejs pionowy to API webowe, przez które przychodzą wywołania z aplikacji klienckiej. Poziomy to broker wiadomości, który jest używany do wymiany danych z innymi wewnętrznymi serwisami.
Przyjrzyjmy się krokom wdrożenia korelacji w każdym z tych interfejsów.
Korelacja w zapytaniach HTTP
Aby uzyskać jak najwięcej informacji, musimy generować identyfikator korelacji jak najwcześniej w aktywności, tj. na bramce lub bezpośrednio na kliencie (mobilnym lub webowym). Ponieważ dzisiaj mamy do czynienia z aplikacją backendową, po prostu zaznaczymy na niej wymóg obecności nagłówka "X-Correlation-ID" we wszystkich zapytaniach do API webowego.
Dodajemy pakiet , którego funkcją jest pobieranie wartości z wymaganego nagłówka
Install-Package CorrelationID
Dodajmy go do potoku obsługi zapytania
public class Startup
{
public void Configure(IApplicationBuilder application)
{
application
.UseCorrelationId(new CorrelationIdOptions
{
Header = "X-Correlation-ID",
IncludeInResponse = false,
UpdateTraceIdentifier = false,
UseGuidForCorrelationId = false
});
}
}
Teraz z jego pomocą stworzymy prosty filtr akcji:
public sealed class 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();
}
}
I dodajemy go do kontrolera
[Route("[controller]")]
[ApiController]
[ServiceFilter(typeof(ApiRequestFilter))]
public class CarsController : ControllerBase
{
}
W wyniku tego kontroler zacznie zwracać 400 Bad request na wszystkie zapytania bez nagłówka z odpowiednim identyfikatorem.
Po tym, jak zaczęliśmy otrzymywać identyfikator od klienta, musimy dodać go do kontekstu rejestrowania, stworzymy do tego obramowującą warstwę:
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(httpContext);
}
}
else
{
await _next(httpContext);
}
}
}
W naszej aplikacji używamy standardowego ILogger z pakietu Microsoft.Extensions.Logging.Abstractions, więc wartość będziemy dodawać za pomocą prostego rozszerzenia do niego.
public static IDisposable BeginScopeWith(this ILogger logger, params (string key, object value)[] keys)
{
return logger.BeginScope(keys.ToDictionary(x => x.key, x => x.value));
}
Dodajemy warstwę do potoku przetwarzania zapytania i uzyskujemy potrzebny rezultat.
public class Startup
{
public void Configure(IApplicationBuilder application)
{
application.UseMiddleware();
}
}
Teraz wszystkie aktywności, które powstają w wyniku zapytań do naszego API internetowego, zawierają identyfikator korelacyjny, dzięki któremu można je łatwo powiązać.
Korelacja w wiadomościach brokera
Kolejnym krokiem będzie skonfigurowanie przekazywania i odbierania identyfikatora korelacji przez brokera wiadomości. W naszym przykładzie użyjemy RabbitMQ, a jako klienta wybierzemy framework MassTransit. Ponownie pominiemy początkową konfigurację pracy z MassTransit i przejdziemy od razu do ustawienia logowania.
Na początek możemy włączyć logi samego MassTransit, w tym celu dodamy do naszej aplikacji pakiet
Install-Package MassTransit.SerilogIntegration
Teraz po dodaniu loggera do ustawień MassTransit będziemy mogli widzieć logi frameworka.
services
.AddSingleton(provider =>
{
return Bus.Factory.CreateUsingRabbitMq(cfg =>
{
cfg.UseSerilog();
});
});
Niech nasza aplikacja w odpowiedzi na żądanie POST wyśle zdarzenie SomethingDoneMessage z wartością „done”. Kontrakt takiej wiadomości można opisać w następujący sposób:
namespace MbMessages
{
public interface ISomethingDoneMessageV1
{
string Value { get; }
}
}
Wiadomości MassTransit są w zasadzie kopertą, do której wkładane są wiadomości brokera. Koperta wygląda mniej więcej tak:
{
"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"
}
}
W wiadomości widoczne są pola serwisowe, które są potrzebne do działania samego frameworka, ale mamy możliwość dodawania do tej koperty swoich dodatkowych właściwości. Co więcej, MassTransit ma wbudowane środki do pracy z niektórymi opcjonalnymi polami, z których najbardziej nas interesuje identyfikator korelacji CorrelationId.
Dodajemy do kontraktu wiadomości interfejs CorrelatedBy:
namespace MbMessages
{
public interface ISomethingDoneMessageV1 : CorrelatedBy
{
string Value { get; }
}
}
Realizujemy go i będziemy przypisywać wartość właściwości CorrelationId podczas tworzenia wiadomości:
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; }
}
Jeśli spojrzymy na zaktualizowaną wiadomość, zobaczymy, że identyfikator korelacji stał się nie tylko częścią naszej wiadomości, ale również częścią koperty — ten identyfikator będzie teraz również używany we wszystkich logach MassTransit, co oznacza, że będziemy znacznie łatwiej radzić sobie z problemami na poziomie brokera wiadomości.
{
"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"
}
}
Pozostaje nam skonfigurować logowanie tych właściwości pomocniczych wiadomości, w tym celu dodamy pakiet do projektu . Pakiet dodaje filtr do przepływu przetwarzania wiadomości MassTransit, który umieszcza kontekst wiadomości w wątkowo-bezpiecznym stosie. Serilog odczytuje kontekst ze stosu i dodaje te dodatkowe właściwości do naszych obiektów logów.
Install-Package Serilog.Enrichers.MassTransitMessage
W MassTransit wstawiamy filtr
services
.AddSingleton(provider =>
{
return Bus.Factory.CreateUsingRabbitMq(cfg =>
{
cfg.UseSerilog();
cfg.UseSerilogMessagePropertiesEnricher();
});
});
A w konfiguracji Seriloga dodajemy wzbogacacz
Log.Logger = new LoggerConfiguration()
.Enrich.FromMassTransitMessage()
.CreateLogger();
Ponieważ aplikacja, która odbiera wiadomość z kolejki RabbitMQ, ma dostęp do wszystkich właściwości koperty MassTransit, możemy wykorzystać uzyskany identyfikator korelacji wewnątrz aplikacji konsumenta, a także przekazywać go dalej w całym łańcuchu wywołań.
W rezultacie nasze logi zawierają CorrelationId nie tylko w obrębie jednego serwisu, ale także podczas interakcji z innymi aplikacjami.
Zatem uzyskany system logowania w aplikacjach .Net pozwala nam bez większych problemów korelować logi z zupełnie różnych mikroserwisów — nawet tych, które działają poprzez brokera wiadomości. A dzięki Elasticsearch możemy szybko i wygodnie analizować logi, tworząc w Kibanie potrzebne nam pulpity (przykład zaprezentowany na obrazku do posta).
Oczywiście, w tej formie logowanie nie pokryje złożonych scenariuszy interakcji między Twoimi usługami a różnymi zewnętrznymi systemami, ale wprowadzenie takiego porządku na samym początku rozwoju projektu to jedna z tych rzeczy, za które wielokrotnie podziękujesz sobie później.
Możesz się przyjrzeć kodowi źródłowemu uzyskanej systemu w projekcie:
Źródło: habr.com
