Rozproszone śledzenie mikroserwisów z OpenTracing i Jaeger

Ostatni wpis zamknął serię związaną z implementacją mikroserwisów jako takich. Jest jednak jeszcze wiele tematów związanych z ich utrzymywaniem i wdrażaniem, które chciałbym sukcesywnie poruszać na blogu. Dziś zaczniemy od moim zdanim kluczowego mechanizmu, bez którego praca z systemem rozproszonym na produkcji może okazać się piekłem.

 

Czym jest rozproszone śledzenie?

Wyobraź sobie, że zakończył się etap implementacji systemu. Trafia on na środowisko produkcyjne, a klienci zaczynają go używać. Aplikacja działa stabilnie dniami, tygodniami… aż tu nagle otrzymujesz zgłoszenie „klientowi X nie działa funkcjonalność Y”. Co może być przyczyną takie stanu rzeczy? W przypadku gdyby analogiczne zgłoszenie tyczyło się monolitu, diagnostyka systemu byłaby o wiele prostsza. Zawsze możemy zajrzeć do logów, lub stosunkowo łatwo spróbować odtworzyć działanie systemu klienta w celu uzyskania błędu na środowisku deweloperskim. W przypadku mikroserwisów sprawa już nie jest taka prosta, ponieważ jedno klikniecie przycisku w przeglądarce może implikować całą lawinę zdarzeń, kwerend, komend wymienianych synchronicznie bądź asynchronicznie między kilkoma, a nawet kilkudziesięcioma usługami. Znalezienie oraz zrozumienie przyczyny wystąpienia błędu w systemie rozproszonym, gdzie każda usługa jest odpowiedzialna w relatywnie małym stopniu za przebieg całego procesu biznesowego, jest po prostu trudne. I wtedy wchodzi rozproszone śledzenie. Ubrane całe na biało. Distributed tracing – bo o tym będzie dzisiejszy artykuł – mówiąc najogólniej pomoże nam diagnozować oraz wizualizować przepływ danych w naszym rozproszonym systemie dostarczając wielu cennych informacji w postaci prostych grafów przepływu danych, metryk oraz logów.

W jaki sposób to działa? Już spieszę tłumaczyć.

 

Wszystko zaczyna się o Spana… nie od <T>

Cała idea rozproszonego śledzenia opiera się na tzw. spanach (nie mylić ze Span<T> z .NET Core 2.1) – czyli czegoś w rodzaju unit of worków, które są tworzone przez nasz system w określonym miejscu i czasie zależnym od nas. Warto powiedzieć co rozumiem przez stwierdzenie „Unit of work”. Dla aplikacji webowych najogólniejszym UoW będzie przetworzenie żądania HTTP, ale moglibyśmy wyróżnić też bardziej szczegółowe jak np. deserializacja body, zapytanie do bazy danych, zbudowanie DTO i wiele innych. To co posiada każdy taki span to:

  • początek w czasie
  • koniec w czasie
  • ewentualną relację do innego spana. Możliwe są dwie relacje: child (pol. dziecko) oraz follows from (pol. wynikający z)

Poniżej zamieściłem prosty diagram, który powinien szybko zobrazować to co do tej pory napisałem.

 

 

W tym przypadku pomarańczowy span mógłby być wspomnianym przetwarzaniem żądania HTTP, w obrębie którego pobrane zostały jakieś dane np. z Redisa (span w relacji „child”) po czym inna usługa została wywołana poprzez mechanizm web hook (span w relacji „follows”). Oczywiście podane wcześniej „property” spana to trochę za mało, aby móc skutecznie korelować ich grupy w logiczną całość oraz, aby dostarczyć większej wartości naszej diagnostyce. W środku samego obiektu znajdziemy znacznie więcej informacji:

 

 

Zacznijmy od kontekstu, ponieważ zawiera on najważniejsze informacje, które będą kluczowe z punktu widzenia późniejszej implementacji:

  • Trace ID – identyfikator całego „łańcucha”. Dzięki temu możemy łatwo wyszukać wszystkie spany, które zostały „wyprodukowane” w ramach przetwarzania żądania HTTP.
  • Span ID – identyfikator Spana.
  • Baggage – metadane, które możemy propagować z jednego spana do kolejno tworzonych.

Poza samym kontekstem możemy także wyróżnić:

  • Process name – poglądową nazwę konkretnego spana np. „Fetching Redis data”
  • Tagi – służą do filtrowania, ale niektóre wpływają także na wizualizację całego łańcucha
  • Logi – dodatkowe dane diagnostyczne

 

Co będzie potrzebne do zaimplementowania rozproszonego śledzenia?

Wiemy już zatem czym jest distributed tracing oraz znamy podstawowy koncept, na którym operuje ów mechanizm. Potrzebujemy teraz dwóch elementów, aby nasze mikroserwisy mogły być skutecznie śledzone:

  1. Mechanizmu tworzenia i instrumentacji spanów w naszej aplikacji.
  2. Mechanizmu próbkowania, raportowania spanów z aplikacji oraz ich wizualizowania.

Do rozwiązania pierwszego problemu użyjemy OpenTracing. Mówiąc najogólniej jest to API (z implementacją w 9 językach programowania), dzięki któremu możemy łatwo dodać instrumentację spanów dla naszej aplikacji. Jak podkreślają twórcy, OpenTracing nie jest standardem implementacji rozproszonego śledzenia. To bardziej specyfikacja, która została zaimplementowana w ich bibliotekach.

Drugie zadanie z naszej listy powierzymy bibliotece Jaeger. Jest to twór firmy Uber, który dostarczy nam kompletną infrastrukturę, pozwalającą efektywnie raportować spany z naszej aplikacji do zewnętrznego źródła danych, odpytywać dane przy użyciu kwerend oraz wizualizować całe łańcuchy.

Poniżej zobaczysz poglądowy schemat całej infrastruktury, która będzie nam potrzebna, aby rozproszone śledzenia działało w naszym systemie (istnieje także wersja z pośrednim buforem w postaci Kafki):

 

https://www.jaegertracing.io/docs/1.14/architecture/

 

Jak widzisz elementów infrastruktury jest dosyć sporo. Na szczęście jej uruchomienie (do celów deweloperskich i testowych) jest bardzo proste, ponieważ sprowadza się od uruchomienia jednego polecenia dockerowego:

 

docker run -d --name jaeger \
  -p 5775:5775/udp \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 14268:14268 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.14

 

Powyższe poleceni uruchomi kompletną infrastrukturę z domyślnie dobranymi i skonfigurowanymi komponentami (przykładowo domyślnym data storage jest Cassandra). Jeżeli chcesz uruchomić każdą część niezależnie możesz użyć gotowych obrazów Dockerowych z oficjalnego repozytorium. Jeżeli wszystko zostało proprawnie uruchomione, po przejściu pod adres localhost:16686 powinien być dostępny panel UI Jaegera:

 

 

Jak widzisz, aktualnie żadna usługi nie została zarejestrowana, ale to się wkrótce zmieni 🙂

 

Implementacja

Zacznijmy od najbardziej istotnej kwestii. Cała implementacja, która pojawi się w tej części artykułu mu si być naturalnie powielona w każdej usłudze, która ma brać udział w śledzeniu. Oczywiście nie polecam kopiowania kodu, a bardziej wyniesienia go do jakiejś współdzielonej paczki NuGet-owej, którą mogłaby pobrać każda usługa.

Na początku dodajmy zależności do naszej usługi. Będą to wspomniane wcześniej OpenTracing or Jaeger:

 

 <ItemGroup>
    <PackageReference Include="Jaeger" Version="0.3.6" /> 
    <PackageReference Include="OpenTracing.Contrib.NetCore" Version="0.6.2" />
  </ItemGroup>

 

Tutaj ważna informacja w odniesieniu do tego co pisałem o paczkach NuGet. Niestety OpenTracing nie targetuje .NET Standard, a jedynie .NET Core App. Oznacza to, że jeżeli zdecydujesz się na wyniesie kodu infrastrukturalnego „na zewnątrz” musisz umieści w nim target netcoreapp. Alternatywą jest wyniesienie części Jaegera jako netstandard, a zależność OpenTracing dodawać jawnie do każdej usługi.

Możemy teraz przejść do budowy i rejestracji w naszej aplikacji tzw. Tracera czyli obiektu, który będzie odpowiedzialny za wszystko co związane ze spanami w naszej aplikacji. Do utworzenia tracera potrzebujemy dwóch rzeczy:

  • sampler – jest to mechanizm próbkowania wytworzonych spanów. Z pobudek czysto wydajnościowych rozsądnym wydaje się, aby nie wszystkie spany raportować do Jaeger, ponieważ mógłby być to zbyt duży narzut dla aplikacji. Jaeger udostępnia kilka strategii samplowania: Constant, Probabilistic, Rate Limiting, Remote. Więcej informacji o samym procesie próbkowania możesz znaleźć tutaj.
  • reporter – jest to mechanizm przekazywania spanów do  collectora. Domyślnie Jaeger używa reportera UDP (znów dla wydajności).

Znając teorię możemy zaimplementować rejestrację tracera w usłudze:

 

//Startup.cs
services.AddSingleton<ITracer>(sp =>
{
    var loggerFactory = sp.GetRequiredService<ILoggerFactory>();
    var options = sp.GetService<JaegerOptions>();

    var reporter = new RemoteReporter.Builder()
        .WithSender(new UdpSender(options.UdpHost, options.UdpPort, options.MaxPacketSize))
        .WithLoggerFactory(loggerFactory)
        .Build();

    var sampler = GetSampler(options);

    var tracer = new Tracer.Builder(options.ServiceName)
        .WithLoggerFactory(loggerFactory)
        .WithReporter(reporter)
        .WithSampler(sampler)
        .Build();

    GlobalTracer.Register(tracer);
    return tracer;
    
    ISampler GetSampler(JaegerOptions options)
        => options.Sampler switch
        {
            "const" => (ISampler) new ConstSampler(true),
            "rate" => new RateLimitingSampler(options.MaxTracesPerSecond),
            "probabilistic" => new ProbabilisticSampler(options.SamplingRate),
            _ => new ConstSampler(true)
        };
});

 

Jak widzisz kod jest bardzo prosty i robi dokładnie to czego można było się spodziewać. Po pierwsze użyte zostaję opcja dla Jaegera, które definiowane są w pliku appsettings.json, a na starcie aplikacji przypisane zostają do obiektu JaegerOptions. Dzięki temu podejściu będziemy w stanie zmieniać ustawienia naszego śledzenia bez konieczności przebudowy całej aplikacji. Same ustawienia prezentują się następująco:

 


  "jaeger": {
    "serviceName": "orders",
    "udpHost": "localhost",
    "udpPort": 6831,
    "maxPacketSize": 0,
    "sampler": "const"
  },

 

Następnie na bazie ustawień zbudowany zostaje kolejno reporter (wspomniany UDP) oraz sampler, który wykorzystuje nowość z C# 8 tj. switch expression, aby dostarczyć odpowiednią strategię samego próbkowania. Wszystko sprowadza się oczywiście od zbudowania na bazie tych komponentów tracera, któremu nadajemy także odpowiednią nazwę, która pojawi się w UI w dropdownie „services”.  Warto zwrócić uwagę, że powyższy kod odpowiada jedynie za samą konfigurację Jaegera, ale nie dodaje nam żadnej instrumentacji spanów. Do tego celu wywołamy metodę rozszerzającą dostarczoną przez sam OpenTracing:

 


services.AddOpenTracing();

 

Ta jedna linijka sparwi, że nasza aplikacja zacznie już generować bardzo ogólne spany, które tworzone są w dostarczonych przez OpenTracing middlewarach ASP.NET Core. Możemy uruchomić nasze usługi i zobaczymy co się stanie! Na potrzeby tego artykułu uruchomię przykładowy system składający się z 3 usług:

  • Orders
  • Pricing
  • Deliveries

Całe „flow” prezentuje się następująco:

  1. Żądanie HTTP dostaje wysłane do usług Orders, które procesuje komendę CreateOrder.
  2. Usługa Orders wysyła żadanie HTTP do usługi Pricing o wycenę zamówienia.
  3. Zwrócona wycena jest użyta do stworzenia obiektu Order. Obiekt zostaje zapisany w bazie Mongo DB.
  4. Po zapisaniu zamówienia usługa orders publikuje zdarzenie OrderCreated.
  5. Na zdarzenie OrderCreated nasłuchuje usługa Deliveries, która tworzy na jego podstawie przejazd.
  6. Po utworzeniu przejazdu usługa Deliveries publikuje zdarzenie DeliveryStarted, na które subskrybuje się usługa Orders.

Bardzo proste flow, które nie ma większego sensu biznesowego, ale jest już wystarczająco skomplikowane aby pokazać zalety rozproszonego śledzenia. Jeżeli Ty również chcesz uruchomić tą aplikację demo to link znajdziesz tutaj (katalog samples).

No dobrze, zobaczmy jak prezentuje się rezultat wysłania żądania HTTP do usługi Orders! W panelu UI Jaegera wybieram z dostępnych usług „Orders”:

 

 

Jak widzisz, jeden z łańcuchów zawiera referencje do dwóch uruchomionych usług. Kliknijmy na niego, aby poznać więcej szczegółów:

 

 

Ekran pełny jest informacji, dlatego przejdźmy przez nie zaczynając od samej góry. Po pierwsze widzimy szczegóły samego łańcucha. Kiedy został zaraportowany, ile trwał (29,52ms), ile usług brało w nim udziału (2) oraz ile sapnów się na niego składa. W naszym przypadku spany były 3:

  1. Span, który określa przetwarzanie żądania POST w usłudze Orders.
  2. Span, który określa przetwarzanie żądania GET  do usługi Pricing.
  3. Span, który określa przetwarzanie żądania GET w samej usłudze Pricing.

W szczegółach każdego z nich mamy kolejne, ciekawe informacje. Wiemy np. że usługa Pricing potrzebowała jedynie 5.28ms aby przetworzyć żądanie HTTp po swojej stronie. Z kolei w usłudze Orders przetwarzanie HTTP GET trwało 12.17ms co pozwala określić nam latency na poziomie 7ms. Oprócz tego mamy do dyspozycji także tagi, po których moglibyśmy filtrować konkretne łańcuchy w głównym widoku Jaegera.

Warto wspomnieć, że powyższa reprezentacja graficzna nie jest jedyną. Mamy do dyspozycji również graf naszego łańcucha:

 

 

Oraz poglądowy graf zależności pomiędzy usługami:

 

 

 

Tworzenie własnych Spanów

No dobrze, a co w przypadku gdybyśmy chcieli tworzyć własne spany w aplikacji? Być może chcielibyśmy zawrzeć nim połączenie bazodanowe, aby móc diagnozować ewentualne problemy wydajnościowe, albo chcielibyśmy dowiedzieć się ile czasu nasza usługa potrzebuje na przetworzenie komendy w ramach handlera. Rozpatrzmy drugi przykład.

Tak prezentuje się command handler dla wspomnianej komendy CreateOrder:

 


    public class CreateOrderHandler : ICommandHandler<CreateOrder>
    {
        private readonly IMongoRepository<Order, Guid> _repository;
        private readonly IBusPublisher _publisher;
        private readonly IPricingServiceClient _pricingServiceClient;
        private readonly ILogger<CreateOrderHandler> _logger;

        public CreateOrderHandler(IMongoRepository<Order, Guid> repository, IBusPublisher publisher,
            IPricingServiceClient pricingServiceClient, ILogger<CreateOrderHandler> logger)
        {
            _repository = repository;
            _publisher = publisher;
            _pricingServiceClient = pricingServiceClient;
            _logger = logger;
        }

        public async Task HandleAsync(CreateOrder command)
        {
            var exists = await _repository.ExistsAsync(o => o.Id == command.OrderId);
            if (exists)
            {
                throw new InvalidOperationException($"Order with given id: {command.OrderId} already exists!");
            }

            _logger.LogInformation($"Fetching a price for order with id: {command.OrderId}...");
            var pricingDto = await _pricingServiceClient.GetAsync(command.OrderId);
            if (pricingDto is null)
            {
                throw new InvalidOperationException($"Pricing was not found for order: {command.OrderId}");
            }
            
            _logger.LogInformation($"Order with id: {command.OrderId} will cost: {pricingDto.TotalAmount}$.");
            var order = new Order(command.OrderId, command.CustomerId, pricingDto.TotalAmount);
            await _repository.AddAsync(order);
            _logger.LogInformation($"Created an order with id: {command.OrderId}, customer: {command.CustomerId}.");
            await _publisher.PublishAsync(new OrderCreated(order.Id));
        }
    }

 

Chcielibyśmy teraz utworzyć span, który reprezentowałby całe przetwarzanie metody HandleAsync. Zacznijmy od stworzenia prostego dekoratora, aby nie komplikować  implementacji samego handlera:

 


internal class JaegerCommandHandlerDecorator<TCommand> : ICommandHandler<TCommand> where TCommand : class, ICommand
    {
        private ICommandHandler<TCommand> _handler { get; }
        private ITracer _tracer { get; }

        public JaegerCommandHandlerDecorator(ICommandHandler<TCommand> handler, ITracer tracer)
        {
            _handler = handler;
            _tracer = tracer;
        }

        public async Task HandleAsync(TCommand command)
        {
            var commandName = ToUnderscoreCase(command.GetType().Name);
            using var scope = BuildScope(commandName);
            var span = scope.Span;

            try
            {
                span.Log($"Handling a message: {commandName}");
                await _handler.HandleAsync(command);
                span.Log($"Handled a message: {commandName}");
            }
            catch (Exception e)
            {
                span.Log(e.Message);
                span.SetTag(Tags.Error, true);
                throw;
            }
        }

        private IScope BuildScope(string commandName)
        {
            var scope = _tracer
                .BuildSpan($"handling-{commandName}")
                .WithTag("message-type", commandName);

            if (_tracer.ActiveSpan is {})
            {
                scope.AddReference(References.ChildOf, _tracer.ActiveSpan.Context);
            }

            return scope.StartActive(true);
        }

        private static string ToUnderscoreCase(string str)
            => string
                .Concat(str.Select((x, i) => i > 0 && char.IsUpper(x) ? "_" + x.ToString() : x.ToString()))
                .ToLowerInvariant();
    }

 

Zacznijmy od konstruktora. Wstrzyknięty zostaje do niego command handler, który dekorujemy (dość oczywiste) oraz ITracer czyli obiekt, który tworzyliśmy na początku tego paragrafu. W ramach metody HandleAsync zaczynamy od zbudowania tzw. Scope, którym to „opatrzymy” wywołanie dekorowanego handlera. W prywatnej metodzie  BuildScope dzieję się tak na prawdę cała magia. Na początku tworzymy nowy span nadając mu nazwę „processing-<nazwa przetwarzanej komendy>”, dodając tag „message-type”. I znów, ów tag może nam później posłużyć do filtrowania spanów, które dotyczyły komendy np. CreateOrder. Następnie sprawdzone zostaje czy istnieje jakiś aktywny span. Jeżeli tak, referujemy do nowo tworzonego spana w relacji „dziecko”. W naszym przypadku property ActiveSpan nie powinno być nigdy nullem, ponieważ utworzony zostaje domyślny span OpenTracing. Następnie uruchamiamy odliczanie wskazując (poprzez parametr true), że chcemy zastopować czas gdy wywołamy metodę Dispose.  Zwrócony obiekt IScope zawiera właściwość Span, która referuje do nowo utworzonego obiektu. Mamy teraz kilka możliwości. Możemy po pierwsze logować do naszego spana, co uczyniłem przed oraz po wywołaniu command handlera. Po drugie, mamy możliwość dynamicznego dodawania kolejnych tagów. W moim dekoratorze, wywołanie handlera umieściłem w bloku try, a w bloku catch dodałem prostą obsługę ewentualnego wyjątku. Po pierwsze loguje jego treść do spana, a po drugie dodaję tag Error na wartość true. Warto dodać, że jest to jeden z domyślnych tagów zgodny ze specyfikacją OpenTracing i również przez nich dostarczany w postaci statycznej klasy.

Pozostaje jedynie udekorować nasz command handler. Ja użyłem do tego celu biblioteki Scrutor:

 


services.Decorate<ICommandHandler<CreateOrder>, JaegerCommandHandlerDecorator<CreateOrder>>();

 

Uruchamiam ponownie usługę i wywołuję żądanie HTTP POST:

 

 

Nasz span został wyświetlony i zawiera odpowiednie tagi oraz logi. Ciekawiej robi się w przypadku, gdy nasz handler rzuci wyjątek, a dekorator doda tag Error. W głównym UI widzimy stosowny komunikat:

 

 

A w logach spana możemy znaleźć treść samego wyjątku:

 

 

Distributed tracing + RabbitMQ

Czytając artykuł do tego miejsca być może w Twojej głowie narodziło się jedno, ważne pytanie. Dlaczego z przedstawionego flow jedynie dwie usługi zostały zaraportowane do Jaegera? Odpowiedź jest prosta. Domyślnie Jaeger wpiera jedynie komunikację synchroniczną po HTTP. Publikowane do RabbitMQ wiadomości nie zawierają odpowiednich metadanych, które mogłyby w jakiś sposób być użyte przez usługi w celu „przedłużenia łańcucha”. Aby taką funkcjonalność dodać musimy wykonać trochę (choć nie dużo) dodatkowej pracy.

Pomysł jest prosty. W momencie publikowania zdarzenia na exchange RabbitMQ, „dobierzemy się” do aktywnego spana i dokonamy serializacji jego kontekstu, który jak pamiętasz zawiera Trace ID, czyli kluczową dla nas informację. Następnie ów kontekst umieścimy w nagłówku wiadomości. To jednak dopiero połowa zadania. Kolejnym krokiem będzie utworzenie prostego middlewara, który wepnie się w proces subskrybcji wiadomości. W środku dokonamy deserializacji kontekstu, a na jego bazie utworzymy nowy span w usłudze, która wiadomość otrzymała. Dzięki temu gdy span zostanie zaraportowany do Jaegera (z tym samym TraceID), zostanie on wyświetlony w ramach tego samego łańcucha. Proste? Proste!

Zacznijmy od końcam, czyli implementacji wspomnianego middlewara. Jego implementacja będzie bardzo podobna do uprzednio omawianego dekoratora, jednakże będzie ona zawierać kilka modyfikacji:

 


    internal sealed class JaegerPlugin : RabbitMqPlugin
    {
        private readonly ITracer _tracer;

        public JaegerPlugin(ITracer tracer) => _tracer = tracer;

        public override async Task HandleAsync(object message, object correlationContext,
            BasicDeliverEventArgs args)
        {
            var messageName = message.GetType().Name;
            var messageId = args.BasicProperties.MessageId;
            var spanContext = string.Empty;
            if (args.BasicProperties.Headers.TryGetValue("span_context", out var spanContextHeader) &&
                spanContextHeader is byte[] spanContextBytes)
            {
                spanContext = Encoding.UTF8.GetString(spanContextBytes);
            }

            using (var scope = BuildScope(messageName, spanContext))
            {
                var span = scope.Span;
                span.Log($"Started processing: {messageName} [id: {messageId}]");
                try
                {
                    await Next(message, correlationContext, args);
                }
                catch (Exception ex)
                {
                    span.SetTag(Tags.Error, true);
                    span.Log(ex.Message);
                }

                span.Log($"Finished processing: {messageName} [id: {messageId}]");
            }
        }
        
        private IScope BuildScope(string messageName, string serializedSpanContext)
        {
            var spanBuilder = _tracer
                .BuildSpan($"processing-{messageName}")
                .WithTag("message-type", messageName);

            if (string.IsNullOrEmpty(serializedSpanContext))
            {
                return spanBuilder.StartActive(true);
            }

            var spanContext = SpanContext.ContextFromString(serializedSpanContext);

            return spanBuilder
                .AddReference(References.FollowsFrom, spanContext)
                .StartActive(true);
        }
    }

 

Jak widzisz, na początku metody HandleAsync zostaje dokonane sprawdzenie, czy do wiadomości został dodany nagłówek „span_context”. Jeżeli tak, jego zawartość przypisujemy do zmiennej spanContext, a następnie przekazujemy do metody BuildScope. Sama metoda jak wspomniałem wygląda bardzo podobnie do tej z dekoratora. Różnica polega na tym, że tej wersji nie sprawdzamy czy istnieje jakiś aktywny span (ponieważ w przypadku otrzymania wiadomości z kolejki ActiveSpan jest zawsze null), a czy przekazany kontekst zawiera jakieś informacje. Jeżeli tak, deserializuejmy go korzystając ze statycznej metody ContextFromString dostarczonej przez Jaegera. Resztę kodu już znasz 🙂

Pora na drugą stronę całego procesu, czyli publikowanie wiadomości. Zmodyfikujmy nieco nasz handler dla komendy CreateOrder:

 


    public class CreateOrderHandler : ICommandHandler<CreateOrder>
    {
        private readonly IMongoRepository<Order, Guid> _repository;
        private readonly IBusPublisher _publisher;
        private readonly IPricingServiceClient _pricingServiceClient;
        private readonly ILogger<CreateOrderHandler> _logger;
        private readonly ITracer _tracer;

        public CreateOrderHandler(IMongoRepository<Order, Guid> repository, IBusPublisher publisher,
            IPricingServiceClient pricingServiceClient, ITracer tracer, ILogger<CreateOrderHandler> logger)
        {
            _repository = repository;
            _publisher = publisher;
            _pricingServiceClient = pricingServiceClient;
            _tracer = tracer;
            _logger = logger;
        }

        public async Task HandleAsync(CreateOrder command)
        {
            //throw new InvalidOperationException("PLEASE LOG ME TO SPAN!");
            var exists = await _repository.ExistsAsync(o => o.Id == command.OrderId);
            if (exists)
            {
                throw new InvalidOperationException($"Order with given id: {command.OrderId} already exists!");
            }

            _logger.LogInformation($"Fetching a price for order with id: {command.OrderId}...");
            var pricingDto = await _pricingServiceClient.GetAsync(command.OrderId);
            if (pricingDto is null)
            {
                throw new InvalidOperationException($"Pricing was not found for order: {command.OrderId}");
            }
            
            _logger.LogInformation($"Order with id: {command.OrderId} will cost: {pricingDto.TotalAmount}$.");
            var order = new Order(command.OrderId, command.CustomerId, pricingDto.TotalAmount);
            await _repository.AddAsync(order);
            _logger.LogInformation($"Created an order with id: {command.OrderId}, customer: {command.CustomerId}.");
            var spanContext = _tracer.ActiveSpan.Context.ToString();
            await _publisher.PublishAsync(new OrderCreated(order.Id), spanContext: spanContext);
        }
    }

 

W samym handlerze pojawił się znajomy ITracer, z którego w przedostatniej linijce metody HandleAsync wyciągamy kontekst aktywnego spana, po czym serializujemy go używając przeciążonej metody ToString(). Kontekst zostaje przekazany do publishera, który umieści go nagłówku wiadomości. I to tyle! Oczywiście warto wspomnieć, że logika wyciągania tego kontekstu powinna normalnie znajdować się w bramce naszego systemu (API Gateway), ale na potrzeby czysto demonstracyjne taka implementacja jest dopuszczalna. Uruchommy zatem zaktualizowane usługi i po raz ostatni wykonajmy żądanie HTTP POST:

 

 

Tym razem, naszym oczom ukazuje się pełny łańcuch zawierający również spany powstałe w skutek spropagowania kontekstu poprzez RabbitMQ. Daje nam no kompletne spektrum tego co dzieje się w naszym rozproszonym systemie.

 

Podsumowanie

Tytułem podsumowania, myślę, że relatywnie mały nakład pracy potrzebny do zaadoptowania rozproszonego śledzenia w mikroserwisach jest olbrzymią zaletą i może posłużyć jako „karta przetargowa” przy planowaniu kolejnego sprintu. Tym bardziej, że efekty pracy mogą zdecydowanie poprawić jakość utrzymywania oraz diagnozowania potencjalnych problemów w naszej aplikacji.

Na koniec jeszcze mała autoreklama. Wspólnie z Piotrkiem Gankiewiczem pracujemy nad projeketem o nazwie Convey. Jest to zbiór paczek NuGetowych, który pozwala na szybką budowę mikroserwisów przy użyciu gotowych integracji infrastrukturalnych. Jedną z nich jest… Jaeger 🙂 Jeżeli chcesz zobaczyć jak proste może być dodanie Jaeger (i nie tylko!) do Twojej aplikacji to zachęcam Cię serdecznie do obejrzenia demo, gdzie w ciągu godziny budujemy od zera całkiem fajnie działający system rozproszony 🙂

 

 

 


 

Jeżeli interesuje Cię tematyka projektowania/implementacji/wdrażania i utrzymywania mikrousług to zapraszam Cię serdecznie do odwiedzenia strony  https://mikroserwisy.net Jest to nasz kompleksowy kurs online wprowadzający w świat nowoczesnej architektury mikroserwisów z wykorzystaniem metodyki Event Storming oraz najpopularniejszych technologii takich jak:

.NET Core, Docker, Kubernetes, Istio Service Mesh …i wiele innych!

You may also like...