{"id":388655,"date":"2024-06-29T08:05:01","date_gmt":"2024-06-29T08:05:01","guid":{"rendered":"http:\/\/savepearlharbor.com\/?p=388655"},"modified":"-0001-11-30T00:00:00","modified_gmt":"2024-06-29T08:05:01","slug":"","status":"publish","type":"post","link":"https:\/\/savepearlharbor.com\/?p=388655","title":{"rendered":"<span>Distributed Tracing for Microservice Architecture<\/span>"},"content":{"rendered":"<div><!--[--><!--]--><\/div>\n<div id=\"post-content-body\">\n<div>\n<div class=\"article-formatted-body article-formatted-body article-formatted-body_version-2\">\n<div xmlns=\"http:\/\/www.w3.org\/1999\/xhtml\">\n<p>What is distributed tracing? Distributed <a href=\"https:\/\/opentracing.io\/docs\/overview\/what-is-tracing\/\" rel=\"noopener noreferrer nofollow\">tracing<\/a> is a method used to profile and monitor applications, especially those built using a microservices architecture. Distributed tracing helps pinpoint where failures occur and what causes poor performance.<\/p>\n<p>Let\u2019s have a look at a simple prototype. A user fetches information about a shipment from <code>logistic<\/code>service. <code>logistic<\/code>service does some computation and fetches the data from a database. logistic service doesn\u2019t know the actual status of the shipment, so it has to fetch the updated status from another service <code>tracking<\/code> <code>tracking<\/code>service also needs to fetch the data from a database and to do some computation.<\/p>\n<p>In the screenshot below, we see a whole life cycle of the request issued to <code>logistics<\/code>service:<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/0ac\/d6c\/c78\/0acd6cc7800f3b5b5cddab7b9c36bab6\" width=\"941\" height=\"542\"\/><figcaption><\/figcaption><\/figure>\n<ol>\n<li>\n<p>GET request hits endpoint <code>\/shipment\/:id<\/code>in the service <code>logistics<\/code><\/p>\n<\/li>\n<li>\n<p>The service does some internal processing that takes 10 ms (span <code>logistics processing<\/code>.<\/p>\n<\/li>\n<li>\n<p>The service fetches data from the database for 30 ms (span <code>SQL select<\/code>. <\/p>\n<\/li>\n<li>\n<p><code>logistics<\/code>fetches the status of the shipment from another service tracking by sending a GET request to endpoint <code>\/tracking:\/:id<\/code>(span <code>tracking<\/code>. We have detailed information about this part of the journey as well, i.e. how much time <code>tracking<\/code>service used for the processing or how much time the service used for the database operation.<\/p>\n<\/li>\n<\/ol>\n<p>From the screen below, we can see that the request was successful and returned 200. <\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/5b0\/52e\/c9e\/5b052ec9eaaa4b41d520080dae8415d9\" width=\"927\" height=\"890\"\/><figcaption><\/figcaption><\/figure>\n<p>It is especially handy as we didn\u2019t log the response code or created the metadata explicitly: it comes for free from the tracing middleware. <\/p>\n<p>Let\u2019s say we want to profile our logistics service. As we can see, we spend most of the time on the database operation. It would be helpful to see the exact query we issued:<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/f9a\/8c3\/1d9\/f9a8c31d98dd0fd61f6e1fcf436324ed\" width=\"947\" height=\"806\"\/><figcaption><\/figcaption><\/figure>\n<p>Now we can check whether the query was optimal and which tables it affected. The span contains the information about the caller, including the line number and file name, so it is easy to navigate in the source code.<\/p>\n<p>Speaking in general, we can profile any part of the code be it a module or a single function. Such data helps to spot the bottlenecks and make informed decisions about the optimization. <\/p>\n<p>Tracing also automatically creates a snapshot of our architecture (DAG):<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/fcf\/ee6\/7a0\/fcfee67a083984aa3b1f396e3f3bc0fa\" width=\"951\" height=\"802\"\/><figcaption><\/figcaption><\/figure>\n<\/p>\n<p>Obviously, the picture above doesn\u2019t look that impressive. But what happens when we have not 2 services, but 30? Let\u2019s say a user logs in and we need to fetch the information from services such as <code>users,<\/code> <code>settings,<\/code> <code>billing,<\/code>etc. In that case, this diagram would be very handy to understand the actual interactions between our services. The tracing would also reveal which of our services takes the most time or which one is the least reliable. <\/p>\n<p>Tracing also helps to debug the problems in the microservice architecture. Let\u2019s say each of our microservices is up and behaves well on an individual level. However, we have a problem on a system-wide level. I.e. there is a particular combination of input and output data between the microservices that causes a problem. In that case, individual logs from each of the microservices won\u2019t reveal a problem. We need to tie all the logs from the affected microservices and see the whole picture. Tracing is the right instrument to solve such kind of problems. <\/p>\n<h2>Distributed Tracing APIs<\/h2>\n<h3>OpenTracing<\/h3>\n<p>What is OpenTracing? It\u2019s a vendor-agnostic API to help developers easily instrument tracing into their\u00a0codebase. This means that if a developer wants to try out a different distributed tracing system, then instead of repeating the whole instrumentation process for the new distributed tracing system, the developer can simply change the configuration of the Tracer.<\/p>\n<p>Most mental models for tracing descend from Google\u2019s Dapper paper. OpenTracing uses similar nouns and verbs (<a href=\"https:\/\/opentracing.io\/docs\/overview\/\" rel=\"noopener noreferrer nofollow\">source<\/a>):<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/748\/8c3\/a59\/7488c3a598b392cb0140c747cf05071e\" width=\"910\" height=\"240\"\/><figcaption><\/figcaption><\/figure>\n<ol>\n<li>\n<p><strong>Trace<\/strong>: The description of a transaction as it moves through a distributed system.<\/p>\n<\/li>\n<li>\n<p><strong>Span<\/strong>: A named, timed operation representing a piece of the workflow. Spans accept key:value tags as well as fine-grained, timestamped, structured logs attached to the particular span instance.<\/p>\n<\/li>\n<li>\n<p><strong>Span context<\/strong>: Trace information that accompanies the distributed transaction, including when it passes the service to service over the network or through a message bus. The span context contains the trace identifier, span identifier, and any other data that the tracing system needs to propagate to the downstream service.<\/p>\n<\/li>\n<\/ol>\n<p>There are several tracers that <a href=\"https:\/\/opentracing.io\/docs\/supported-tracers\/\" rel=\"noopener noreferrer nofollow\">support<\/a> OpenTracing API, including Jaeger, Instana, and Elastic APM. <\/p>\n<h3>OpenTelemetry<\/h3>\n<p><a href=\"https:\/\/opentelemetry.io\/about\/\" rel=\"noopener noreferrer nofollow\">OpenTelemetry<\/a> is a set of APIs, SDKs, tooling and integrations that are designed for the creation and management of\u00a0<em>telemetry data<\/em>\u00a0such as traces, metrics, and logs. OpenTelemetry is a CNCF Sandbox member, formed through a merger of the OpenTracing and OpenCensus projects.<\/p>\n<p>OpenTelemetry implementation for Go is in pre-GA phase. As of today (15.01.2021), the <a href=\"https:\/\/github.com\/open-telemetry\/opentelemetry-go\/milestones\" rel=\"noopener noreferrer nofollow\">estimated<\/a> percentage of completion for the first release candidate is 72%.<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/209\/d98\/7f4\/209d987f461900e2f50b465e300e4cf6\" width=\"1325\" height=\"281\"\/><figcaption><\/figcaption><\/figure>\n<p>One of the three main components &#8212; logging have not yet been <a href=\"https:\/\/opentelemetry.io\/docs\/go\/\" rel=\"noopener noreferrer nofollow\">implemented<\/a>:<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/366\/7bf\/b39\/3667bfb39d5150f8b13a0b71403209d5\" width=\"683\" height=\"242\"\/><figcaption><\/figcaption><\/figure>\n<p>As OpenTelemetry implementation in Go hasn\u2019t yet matured, this proposal uses OpenTracing standard. Both standards use the same terminology and concepts, so the migration to newer OpenTelemetry should be relatively straightforward. <\/p>\n<h2>Tracers<\/h2>\n<h3>Jaeger<\/h3>\n<p>The <a href=\"https:\/\/www.jaegertracing.io\/\" rel=\"noopener noreferrer nofollow\">Jaeger<\/a> tracing system is an open-source tracing system for microservices, and it supports the\u00a0<a href=\"https:\/\/opentracing.io\/\" rel=\"noopener noreferrer nofollow\"><u>OpenTracing<\/u><\/a>\u00a0standard. Jaeger was initially published as open source by Uber Technologies and has evolved since then. The system gives you distributing tracing, root cause analysis, service dependency analysis, and more.<\/p>\n<h3>New Relic APM<\/h3>\n<p>New Relic APM (Application Performance Monitoring)  provides monitoring of application\u2019s performance and has support for distributed tracing.<\/p>\n<p>New Relic ATM uses the same terminology as OpenTracing with the addition of transaction. At New Relic, a\u00a0<strong>transaction<\/strong>\u00a0is defined as one logical unit of work in a software application. Specifically, it refers to the function calls and method calls that make up that unit of work.\u00a0For APM, it will often refer to a\u00a0<strong>web transaction<\/strong>, which represents an activity that happens from when the application receives a web request to when the response is sent.<\/p>\n<p>New Relic APM has support for the instrumentation of Go <a href=\"https:\/\/docs.newrelic.com\/docs\/agents\/go-agent\/features\/enable-distributed-tracing-your-go-applications\" rel=\"noopener noreferrer nofollow\">applications.<\/a> The API can be found <a href=\"https:\/\/pkg.go.dev\/github.com\/newrelic\/go-agent\/v3\/newrelic#Logger\" rel=\"noopener noreferrer nofollow\">here<\/a>.<\/p>\n<p>New Relic also provides open-source integrations that report telemetry data from telemetry tools to a New Relic account. In particular, it provides an <a href=\"https:\/\/github.com\/newrelic\/opentelemetry-exporter-go\" rel=\"noopener noreferrer nofollow\">exporter<\/a> for sending OpenTelemetry data to New Relic. <\/p>\n<h3>Grafana Tempo<\/h3>\n<p>Grafana Tempo is a tracing backend that implements OpenTelemetry\/OpenTracing standards. <a href=\"https:\/\/grafana.com\/docs\/tempo\/latest\/guides\/loki-derived-fields\/\" rel=\"noopener noreferrer nofollow\">Here<\/a> is example instrumentation with <code>opentelementry<\/code>library.<\/p>\n<h3>Sentry<\/h3>\n<p>Sentry is an application monitoring system with support for <a href=\"https:\/\/docs.sentry.io\/product\/performance\/distributed-tracing\/\" rel=\"noopener noreferrer nofollow\">distributed tracing<\/a>. The API can be found <a href=\"https:\/\/pkg.go.dev\/github.com\/getsentry\/sentry-go\" rel=\"noopener noreferrer nofollow\">here<\/a>.<\/p>\n<h2>Prototype<\/h2>\n<p>Prototype microservices were written in Go and are using OpenTracing API. <\/p>\n<h3>Service logistics<\/h3>\n<p>Service <code>logistics<\/code>exposes a REST endpoint <code>\/shipment\/:id.<\/code>We use <code>echo<\/code>library that has excellent support for the tracing middleware. Note, though, that <code>echo<\/code>is not a hard requirement &#8212; it is possible to write our own tracing middleware and achieve the same result.<\/p>\n<p>We instantiate a logging middleware that automatically logs a response code and some metadata. <\/p>\n<pre><code class=\"go\">SERVICE = \"logistics\"  e := echo.New() os.Setenv(\"JAEGER_SERVICE_NAME\", SERVICE)  \/\/ Enable tracing middleware c := jaegertracing.New(e, nil) defer c.Close()<\/code><\/pre>\n<p>Create a simple handler: <\/p>\n<pre><code class=\"go\">e.GET(\"\/shipment\/:id\", func(c echo.Context) error {    sp := jaegertracing.CreateChildSpan(c, \"get shipment request\")    defer sp.Finish()     id := c.Param(\"id\")     processing(c, id)    shipment := getShipmentFromDatabase(c, id)    shipment.Status = fetchStatus(c, id)    time.Sleep(time.Millisecond * 15)     return c.JSON(http.StatusOK, shipment) })<\/code><\/pre>\n<p>We create the child span <code>sp<\/code>from the context. The \u201c<strong>span<\/strong>\u201d is the primary building block of a distributed trace, representing an individual unit of work done in a distributed system. Each component of the distributed system contributes a span &#8212; a named, timed operation representing a piece of the workflow.<\/p>\n<p>After successful processing, we respond with status code 200 and return the shipment information as a JSON.<\/p>\n<p>Function <code>processing<\/code>simulates some internal processing:<\/p>\n<pre><code class=\"go\">func processing(c echo.Context, id string) {    sp := jaegertracing.CreateChildSpan(c, \"logistic processing\")    defer sp.Finish()     \/\/ simulate the workload    time.Sleep(time.Millisecond * 10)     sp.LogKV(\"successfully processed shipment\", id) }<\/code><\/pre>\n<p>In this function, we added a structured <strong>logging<\/strong> record by calling <code>sp.LogKV<\/code>.<\/p>\n<p>Function <code>getShipmentFromDatabase<\/code>simulates a database operation:<\/p>\n<pre><code class=\"go\">type shipment struct {     ID      string     Status  string     Carrier string }  func getShipmentFromDatabase(c echo.Context, id string) shipment {    sp := jaegertracing.CreateChildSpan(c, \"SQL select\")    defer sp.Finish()    sp.SetTag(\"sql.query\", fmt.Sprintf(\"SELECT * FROM shipment WHERE id = %s\", id))     time.Sleep(time.Millisecond * 30) \/\/ simulate a select operation    return shipment{ID: id, Status: \"dispatched\"} }<\/code><\/pre>\n<p>In this function, we added a <strong>tag<\/strong> to the span by calling <code>sp.SetTag<\/code> When should we use a tag and when should we use a logging record? Usually, a tag describes some characteristic that is true during the whole span. While a logging record describes an event that happened at a particular timestamp. <\/p>\n<p>Now we have to fetch the status of the shipment from service <code>tracking<\/code> How do we pass the tracking info across the boundaries between the services? Our <code>GlobalTracer<\/code>singleton injects the span information into the headers of the request to <code>tracking<\/code> service:<\/p>\n<pre><code class=\"go\">func fetchStatus(c echo.Context, id string) string {    sp := jaegertracing.CreateChildSpan(c, \"fetch status from tracking service\")    defer sp.Finish()     url := fmt.Sprintf(\"http:\/\/localhost:8080\/tracking\/%s\", id)    req, err := http.NewRequest(http.MethodGet, url, nil)    if err != nil {       panic(err)    }     opentracing.GlobalTracer().Inject(       sp.Context(),       opentracing.HTTPHeaders,       opentracing.HTTPHeadersCarrier(req.Header))     res, err := http.DefaultClient.Do(req)    if err != nil {       panic(err)    }    defer res.Body.Close()     status, err := ioutil.ReadAll(res.Body)    if err != nil {       panic(err)    }     return string(status) }<\/code><\/pre>\n<p>Specifically, the tracer package added the following header to the request to tracking service.<\/p>\n<pre><code>Uber-Trace-Id: 679420a750136ab6:413a9aeeefd2abe8:679420a750136ab6:1<\/code><\/pre>\n<p>With this information <code>tracking<\/code>service is able to continue the trace.<\/p>\n<h3>Service tracking<\/h3>\n<p><code>tracking<\/code>service is quite similar to <code>logistic<\/code>service. Here it&#8217;s full listing:<\/p>\n<pre><code class=\"go\">package main  import (    \"fmt\"    \"io\/ioutil\"    \"net\/http\"    \"os\"    \"time\"     \"github.com\/labstack\/echo-contrib\/jaegertracing\"    \"github.com\/labstack\/echo\/v4\"    \"github.com\/opentracing\/opentracing-go\" )  const (    SERVICE = \"logistics\" )  func main() {    e := echo.New()    os.Setenv(\"JAEGER_SERVICE_NAME\", SERVICE)     \/\/ Enable tracing middleware    c := jaegertracing.New(e, nil)    defer c.Close()     e.GET(\"\/shipment\/:id\", func(c echo.Context) error {       sp := jaegertracing.CreateChildSpan(c, \"get shipment request\")       defer sp.Finish()        id := c.Param(\"id\")        processing(c, id)       shipment := getShipmentFromDatabase(c, id)       shipment.Status = fetchStatus(c, id)       time.Sleep(time.Millisecond * 15)        return c.JSON(http.StatusOK, shipment)    })    e.Logger.Fatal(e.Start(\":1323\")) }  type shipment struct {    ID      string    Status  string    Carrier string }  \/\/ simulate some processing func processing(c echo.Context, id string) {    sp := jaegertracing.CreateChildSpan(c, \"logistic processing\")    defer sp.Finish()     \/\/ simulate the workload    time.Sleep(time.Millisecond * 10)     sp.LogKV(\"successfully processed shipment\", id) }  \/\/ database dependency func getShipmentFromDatabase(c echo.Context, id string) shipment {    sp := jaegertracing.CreateChildSpan(c, \"SQL select\")    defer sp.Finish()    sp.SetTag(\"sql.query\", fmt.Sprintf(\"SELECT * FROM shipment WHERE id = %s\", id))     time.Sleep(time.Millisecond * 30) \/\/ simulate a select operation    return shipment{ID: id, Status: \"dispatched\", Carrier: \"UPS\"} }  \/\/ external dependency: tracking service func fetchStatus(c echo.Context, id string) string {    sp := jaegertracing.CreateChildSpan(c, \"fetch status from tracking service\")    defer sp.Finish()     url := fmt.Sprintf(\"http:\/\/localhost:8080\/tracking\/%s\", id)    req, err := http.NewRequest(http.MethodGet, url, nil)    if err != nil {       panic(err)    }     opentracing.GlobalTracer().Inject(       sp.Context(),       opentracing.HTTPHeaders,       opentracing.HTTPHeadersCarrier(req.Header))     res, err := http.DefaultClient.Do(req)    if err != nil {       panic(err)    }    defer res.Body.Close()     status, err := ioutil.ReadAll(res.Body)    if err != nil {       panic(err)    }     return string(status) } <\/code><\/pre>\n<h3>Jaeger<\/h3>\n<p>We run an all-in-one Docker container for Jaeger:<\/p>\n<pre><code>jaegar:    docker run -d -p6831:6831\/udp -p16686:16686 jaegertracing\/all-in-one:latest<\/code><\/pre>\n<p>Jaeger UI will be accessible on port 16686<\/p>\n<h3>Demo<\/h3>\n<p>We issue a GET request to <code>logistic<\/code>service and receive the response:<\/p>\n<pre><code>$ http localhost:1323\/shipment\/134324                                                      aynur@aynur-manjaro HTTP\/1.1 200 OK Content-Length: 61 Content-Type: application\/json; charset=UTF-8 Date: Fri, 15 Jan 2021 17:54:28 GMT  {     \"Carrier\": \"UPS\",     \"ID\": \"134324\",     \"Status\": \"dispatched_to_hub\" }  <\/code><\/pre>\n<p>Jaeger UI displays all recorded traces for logistic service:<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/8a7\/e58\/0db\/8a7e580db88ab896169f3c453aff8e73\" width=\"927\" height=\"880\"\/><figcaption><\/figcaption><\/figure>\n<p>We search a trace for the requested shipment by tag shipment_id (search panel on the right):<\/p>\n<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/f32\/0d9\/b1a\/f320d9b1a4d954ba7cdde850f712b408\" width=\"940\" height=\"499\"\/><figcaption><\/figcaption><\/figure>\n<\/p>\n<p>The trace contains in-depth information about the request\u2019s life cycle:<\/p>\n<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/d23\/1b3\/208\/d231b3208e60f190ab4da6a24fb6a1ee\" width=\"947\" height=\"493\"\/><figcaption><\/figcaption><\/figure>\n<\/p>\n<p>The information can also be represented as a graph:<\/p>\n<figure class=\"full-width\"><img loading=\"lazy\" decoding=\"async\" src=\"https:\/\/habrastorage.org\/getpro\/habr\/upload_files\/680\/8fa\/cc3\/6808facc332395f4fbe226fd8e5fd0d5\" width=\"899\" height=\"301\"\/><figcaption><\/figcaption><\/figure>\n<h2>Conclusion<\/h2>\n<p>Distributed tracing is a powerful method that used to profile and monitor applications, especially those built using a microservices architecture. As an individual squad doesn\u2019t have too many microservices, the introduction of the tracing would be most beneficial on a company-wide level or at least on a department level.<\/p>\n<h2><\/h2>\n<\/p>\n<\/div>\n<\/div>\n<\/div>\n<p><!----><!----><\/div>\n<p><!----><!----><br \/> \u0441\u0441\u044b\u043b\u043a\u0430 \u043d\u0430 \u043e\u0440\u0438\u0433\u0438\u043d\u0430\u043b \u0441\u0442\u0430\u0442\u044c\u0438 <a href=\"https:\/\/habr.com\/ru\/articles\/539022\/\"> https:\/\/habr.com\/ru\/articles\/539022\/<\/a><\/p>\n","protected":false},"excerpt":{"rendered":"<div><!--[--><!--]--><\/div>\n<div id=\"post-content-body\">\n<div>\n<div class=\"article-formatted-body article-formatted-body article-formatted-body_version-2\">\n<div xmlns=\"http:\/\/www.w3.org\/1999\/xhtml\">\n<p>What is distributed tracing? Distributed <a href=\"https:\/\/opentracing.io\/docs\/overview\/what-is-tracing\/\" rel=\"noopener noreferrer nofollow\">tracing<\/a> is a method used to profile and monitor applications, especially those built using a microservices architecture. Distributed tracing helps pinpoint where failures occur and what causes poor performance.<\/p>\n<p>Let\u2019s have a look at a simple prototype. A user fetches information about a shipment from <code>logistic<\/code>service. <code>logistic<\/code>service does some computation and fetches the data from a database. logistic service doesn\u2019t know the actual status of the shipment, so it has to fetch the updated status from another service <code>tracking<\/code> <code>tracking<\/code>service also needs to fetch the data from a database and to do some computation.<\/p>\n<p>In the screenshot below, we see a whole life cycle of the request issued to <code>logistics<\/code>service:<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<ol>\n<li>\n<p>GET request hits endpoint <code>\/shipment\/:id<\/code>in the service <code>logistics<\/code><\/p>\n<\/li>\n<li>\n<p>The service does some internal processing that takes 10 ms (span <code>logistics processing<\/code>.<\/p>\n<\/li>\n<li>\n<p>The service fetches data from the database for 30 ms (span <code>SQL select<\/code>. <\/p>\n<\/li>\n<li>\n<p><code>logistics<\/code>fetches the status of the shipment from another service tracking by sending a GET request to endpoint <code>\/tracking:\/:id<\/code>(span <code>tracking<\/code>. We have detailed information about this part of the journey as well, i.e. how much time <code>tracking<\/code>service used for the processing or how much time the service used for the database operation.<\/p>\n<\/li>\n<\/ol>\n<p>From the screen below, we can see that the request was successful and returned 200. <\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<p>It is especially handy as we didn\u2019t log the response code or created the metadata explicitly: it comes for free from the tracing middleware. <\/p>\n<p>Let\u2019s say we want to profile our logistics service. As we can see, we spend most of the time on the database operation. It would be helpful to see the exact query we issued:<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<p>Now we can check whether the query was optimal and which tables it affected. The span contains the information about the caller, including the line number and file name, so it is easy to navigate in the source code.<\/p>\n<p>Speaking in general, we can profile any part of the code be it a module or a single function. Such data helps to spot the bottlenecks and make informed decisions about the optimization. <\/p>\n<p>Tracing also automatically creates a snapshot of our architecture (DAG):<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<\/p>\n<p>Obviously, the picture above doesn\u2019t look that impressive. But what happens when we have not 2 services, but 30? Let\u2019s say a user logs in and we need to fetch the information from services such as <code>users,<\/code> <code>settings,<\/code> <code>billing,<\/code>etc. In that case, this diagram would be very handy to understand the actual interactions between our services. The tracing would also reveal which of our services takes the most time or which one is the least reliable. <\/p>\n<p>Tracing also helps to debug the problems in the microservice architecture. Let\u2019s say each of our microservices is up and behaves well on an individual level. However, we have a problem on a system-wide level. I.e. there is a particular combination of input and output data between the microservices that causes a problem. In that case, individual logs from each of the microservices won\u2019t reveal a problem. We need to tie all the logs from the affected microservices and see the whole picture. Tracing is the right instrument to solve such kind of problems. <\/p>\n<h2>Distributed Tracing APIs<\/h2>\n<h3>OpenTracing<\/h3>\n<p>What is OpenTracing? It\u2019s a vendor-agnostic API to help developers easily instrument tracing into their\u00a0codebase. This means that if a developer wants to try out a different distributed tracing system, then instead of repeating the whole instrumentation process for the new distributed tracing system, the developer can simply change the configuration of the Tracer.<\/p>\n<p>Most mental models for tracing descend from Google\u2019s Dapper paper. OpenTracing uses similar nouns and verbs (<a href=\"https:\/\/opentracing.io\/docs\/overview\/\" rel=\"noopener noreferrer nofollow\">source<\/a>):<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<ol>\n<li>\n<p><strong>Trace<\/strong>: The description of a transaction as it moves through a distributed system.<\/p>\n<\/li>\n<li>\n<p><strong>Span<\/strong>: A named, timed operation representing a piece of the workflow. Spans accept key:value tags as well as fine-grained, timestamped, structured logs attached to the particular span instance.<\/p>\n<\/li>\n<li>\n<p><strong>Span context<\/strong>: Trace information that accompanies the distributed transaction, including when it passes the service to service over the network or through a message bus. The span context contains the trace identifier, span identifier, and any other data that the tracing system needs to propagate to the downstream service.<\/p>\n<\/li>\n<\/ol>\n<p>There are several tracers that <a href=\"https:\/\/opentracing.io\/docs\/supported-tracers\/\" rel=\"noopener noreferrer nofollow\">support<\/a> OpenTracing API, including Jaeger, Instana, and Elastic APM. <\/p>\n<h3>OpenTelemetry<\/h3>\n<p><a href=\"https:\/\/opentelemetry.io\/about\/\" rel=\"noopener noreferrer nofollow\">OpenTelemetry<\/a> is a set of APIs, SDKs, tooling and integrations that are designed for the creation and management of\u00a0<em>telemetry data<\/em>\u00a0such as traces, metrics, and logs. OpenTelemetry is a CNCF Sandbox member, formed through a merger of the OpenTracing and OpenCensus projects.<\/p>\n<p>OpenTelemetry implementation for Go is in pre-GA phase. As of today (15.01.2021), the <a href=\"https:\/\/github.com\/open-telemetry\/opentelemetry-go\/milestones\" rel=\"noopener noreferrer nofollow\">estimated<\/a> percentage of completion for the first release candidate is 72%.<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<p>One of the three main components &#8212; logging have not yet been <a href=\"https:\/\/opentelemetry.io\/docs\/go\/\" rel=\"noopener noreferrer nofollow\">implemented<\/a>:<\/p>\n<figure class=\"full-width\"><figcaption><\/figcaption><\/figure>\n<p>As OpenTelemetry implementation in Go hasn\u2019t yet matured, this proposal uses OpenTracing standard. Both standards use the same terminology and concepts, so the migration to newer OpenTelemetry should be relatively straightforward. <\/p>\n<h2>Tracers<\/h2>\n<h3>Jaeger<\/h3>\n<p>The <a href=\"https:\/\/www.jaegertracing.io\/\" rel=\"noopener noreferrer nofollow\">Jaeger<\/a> tracing system is an open-source tracing system for microservices, and it supports the\u00a0<a href=\"https:\/\/opentracing.io\/\" rel=\"noopener noreferrer nofollow\"><u>OpenTracing<\/u><\/a>\u00a0standard. Jaeger was initially published as open source by Uber Technologies and has evolved since then. The system gives you distributing tracing, root cause analysis, service dependency analysis, and more.<\/p>\n<h3>New Relic APM<\/h3>\n<p>New Relic APM (Application Performance Monitoring)  provides monitoring of application\u2019s performance and has support for distributed tracing.<\/p>\n<p>New Relic ATM uses the same terminology as OpenTracing with the addition of transaction. At New Relic, a\u00a0<strong>transaction<\/strong>\u00a0is defined as one logical unit of work in a software application. Specifically, it refers to the function calls and method calls that make up that unit of work.\u00a0For APM, it will often refer to a\u00a0<strong>web transaction<\/strong>, which represents an activity that happens from when the application receives a web request to when the response is sent.<\/p>\n<p>New Relic APM has support for the instrumentation of Go <a href=\"https:\/\/docs.newrelic.com\/docs\/agents\/go-agent\/features\/enable-distributed-tracing-your-go-applications\" rel=\"noopener noreferrer nofollow\">applications.<\/a> The API can be found <a href=\"https:\/\/pkg.go.dev\/github.com\/newrelic\/go-agent\/v3\/newrelic#Logger\" rel=\"noopener noreferrer nofollow\">here<\/a>.<\/p>\n<p>New Relic also provides open-source integrations that report telemetry data from telemetry tools to a New Relic account. In particular, it provides an <a href=\"https:\/\/github.com\/newrelic\/opentelemetry-exporter-go\" rel=\"noopener noreferrer nofollow\">exporter<\/a> for sending OpenTelemetry data to New Relic. <\/p>\n<h3>Grafana Tempo<\/h3>\n<p>Grafana Tempo is a tracing backend that implements OpenTelemetry\/OpenTracing standards. <a href=\"https:\/\/grafana.com\/docs\/tempo\/latest\/guides\/loki-derived-fields\/\" rel=\"noopener noreferrer nofollow\">Here<\/a> is example instrumentation with <code>opentelementry<\/code>library.<\/p>\n<h3>Sentry<\/h3>\n<p>Sentry is an application monitoring system with support for <a href=\"https:\/\/docs.sentry.io\/product\/performance\/distributed-tracing\/\" rel=\"noopener noreferrer nofollow\">distributed tracing<\/a>. The API can be found <a href=\"https:\/\/pkg.go.dev\/github.com\/getsentry\/sentry-go\" rel=\"noopener noreferrer nofollow\">here<\/a>.<\/p>\n<h2>Prototype<\/h2>\n<p>Prototype microservices were written in Go and are using OpenTracing API. <\/p>\n<h3>Service logistics<\/h3>\n<p>Service <code>logistics<\/code>exposes a REST endpoint <code>\/shipment\/:id.<\/code>We use <code>echo<\/code>library that has excellent support for the tracing middleware. Note, though, that <code>echo<\/code>is not a hard requirement &#8212; it is possible to write our own tracing middleware and achieve the same result.<\/p>\n<p>We instantiate a logging middleware that automatically logs a response code and some metadata. <\/p>\n<pre><code class=\"go\">SERVICE = \"logistics\"  e := echo.New() os.Setenv(\"JAEGER_SERVICE_NAME\", SERVICE)  \/\/ Enable tracing middleware c := jaegertracing.New(e, nil) defer c.Close()<\/code><\/pre>\n<p>Create a simple handler: <\/p>\n<pre><code class=\"go\">e.GET(\"\/shipment\/:id\", func(c echo.Context) error {    sp := jaegertracing.CreateChildSpan(c, \"get shipment request\")    defer sp.Finish()     id := c.Param(\"id\")     processing(c, id)    shipment := getShipmentFromDatabase(c, id)    shipment.Status = fetchStatus(c, id)    time.Sleep(time.Millisecond * 15)     return c.JSON(http.StatusOK, shipment) })<\/code><\/pre>\n<p>We create the child span <code>sp<\/code>from the context. The \u201c<strong>span<\/strong>\u201d is the primary building block of a distributed trace, representing an individual unit of work done in a distributed system. Each component of the distributed system contributes a span &#8212; a named, timed operation representing a piece of the workflow.<\/p>\n<p>After successful processing, we respond with status code 200 and return the shipment information as a JSON.<\/p>\n<p>Function <code>processing<\/code>simulates some internal processing:<\/p>\n<pre><code class=\"go\">func processing(c echo.Context, id string) {    sp := jaegertracing.CreateChildSpan(c, \"logistic processing\")    defer sp.Finish()     \/\/ simulate the workload    time.Sleep(time.Millisecond * 10)     sp.LogKV(\"successfully processed shipment\", id) }<\/code><\/pre>\n<p>In this function, we added a structured <strong>logging<\/strong> record by calling <code>sp.LogKV<\/code>.<\/p>\n<p>Function <code>getShipmentFromDatabase<\/code>simulates a database operation:<\/p>\n<pre><code class=\"go\">type shipment struct {     ID      string     Status  string     Carrier string }  func getShipmentFromDatabase(c echo.Context, id string) shipment {    sp := jaegertracing.CreateChildSpan(c, \"SQL select\")    defer sp.Finish()    sp.SetTag(\"sql.query\", fmt.Sprintf(\"SELECT * FROM shipment WHERE id = %s\", id))     time.Sleep(time.Millisecond * 30) \/\/ simulate a select operation    return shipment{ID: id, Status: \"dispatched\"} }<\/code><\/pre>\n<p>In this function, we added a <strong>tag<\/strong> to the span by calling <code>sp.SetTag<\/code> When should we use a tag and when should we use a logging record? Usually, a tag describes some characteristic that is true during the whole span. While a logging record describes an event that happened at a particular timestamp. <\/p>\n<p>Now we have to fetch the status of the shipment from service <code>tracking<\/code> How do we pass the tracking info across the boundaries between the services? Our <code>GlobalTracer<\/code>singleton injects the span information into the headers of the request to <code>tracking<\/code> service:<\/p>\n<pre><code class=\"go\">func fetchStatus(c echo.Context, id string) string {    sp := jaegertracing.CreateChildSpan(c, \"fetch status from tracking service\")    defer sp.Finish()     url := fmt.Sprintf(\"http:\/\/localhost:8080\/tracking\/%s\", id)    req, err := http.NewRequest(http.MethodGet, url, nil)    if err != nil {       panic(err)    }     opentracing.GlobalTracer().Inject(       sp.Context(),       opentracing.HTTPHeaders,       opentracing.HTTPHeadersCarrier(req.Header))     res, err := http.DefaultClient.Do(req)    if err != nil {       <\/code><\/pre>\n<\/div>\n<\/div>\n<\/div>\n<\/div>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[],"tags":[],"class_list":["post-388655","post","type-post","status-publish","format-standard","hentry"],"_links":{"self":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts\/388655","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcomments&post=388655"}],"version-history":[{"count":0,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=\/wp\/v2\/posts\/388655\/revisions"}],"wp:attachment":[{"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fmedia&parent=388655"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Fcategories&post=388655"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/savepearlharbor.com\/index.php?rest_route=%2Fwp%2Fv2%2Ftags&post=388655"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}