DEV Community

Muhammad Syukur Abadi
Muhammad Syukur Abadi

Posted on

Application Tracing With Golang, OpenTelemetry, and Grafana Tempo

#opentelemetry #go #tracing #grafana

Trace

Trace is a record or history from a request. Trace give us big picture abour what is happening from application accepts request to return a response. This record is build above span.

Span

Span is a unit that records particular operation within certain time window. Span contains information about trace name, timestamp from request starts to when it ends, and other informations in form of span attributes such as HTTP request, HTTP URL, and URL path. This is an example of hello span on json format.

{ "name": "hello", "context": { "trace_id": "5b8aa5a2d2c872e8321cf37308d69df2", "span_id": "051581bf3cb55c13" }, "parent_id": null, "start_time": "2022-04-29T18:52:58.114201Z", "end_time": "2022-04-29T18:52:58.114687Z", "attributes": { "http.route": "some_route1" }, "events": [ { "name": "Guten Tag!", "timestamp": "2022-04-29T18:52:58.114561Z", "attributes": { "event_attributes": 1 } } ] }
Enter fullscreen mode Exit fullscreen mode

Span above contains informations about

  • a name hello
  • span lifetime on start_time and end_time fields
  • http.route span attribute records information URL
  • event field that tells us what happens during span lifetime

Span hello is a parent span, because value on parent_id field is null. Pay attention on hello_greetings span below.

{ "name": "hello-greetings", "context": { "trace_id": "5b8aa5a2d2c872e8321cf37308d69df2", "span_id": "5fb397be34d26b51" }, "parent_id": "051581bf3cb55c13", "start_time": "2022-04-29T18:52:58.114304Z", "end_time": "2022-04-29T22:52:58.114561Z", "attributes": { "http.route": "some_route2" }, "events": [ { "name": "hey there!", "timestamp": "2022-04-29T18:52:58.114561Z", "attributes": { "event_attributes": 1 } }, { "name": "bye now!", "timestamp": "2022-04-29T18:52:58.114585Z", "attributes": { "event_attributes": 1 } } ] }
Enter fullscreen mode Exit fullscreen mode

Value of parent_id field on greetings span is same as value of span_id on hello span. We call greetings span is a child span from hello span. Below is hello-salutation span, where it's parent_id is equal to hello's span_id.

{ "name": "hello-salutations", "context": { "trace_id": "5b8aa5a2d2c872e8321cf37308d69df2", "span_id": "93564f51e1abe1c2" }, "parent_id": "051581bf3cb55c13", "start_time": "2022-04-29T18:52:58.114492Z", "end_time": "2022-04-29T18:52:58.114631Z", "attributes": { "http.route": "some_route3" }, "events": [ { "name": "hey there!", "timestamp": "2022-04-29T18:52:58.114561Z", "attributes": { "event_attributes": 1 } } ] }
Enter fullscreen mode Exit fullscreen mode

OpenTelemetry Collector

Collector is a component to receive, extract, and export telemetry data. OpenTelemetry collector is use to receive, extract, and export telemetry data in various formats such as Jaeger, Prometheus, or FluentBit. OpenTelemetry collector built above several components:

  1. Receiver

Receiver focus on collecting data from various sources and formats. Here is an example of receiver.

receivers: # Data sources: logs fluentforward: endpoint: 0.0.0.0:8006 # Data sources: metrics hostmetrics: scrapers: cpu: disk: filesystem: load: memory: network: process: processes: paging: # Data sources: traces jaeger: protocols: grpc: endpoint: 0.0.0.0:4317 thrift_binary: thrift_compact: thrift_http: # Data sources: traces, metrics, logs kafka: protocol_version: 2.0.0 # Data sources: traces, metrics opencensus: # Data sources: traces, metrics, logs otlp: protocols: grpc: endpoint: 0.0.0.0:4317 tls: cert_file: cert.pem key_file: cert-key.pem http: endpoint: 0.0.0.0:4318 # Data sources: metrics prometheus: config: scrape_configs: - job_name: otel-collector scrape_interval: 5s static_configs: - targets: [localhost:8888] # Data sources: traces zipkin:
Enter fullscreen mode Exit fullscreen mode
  1. Processor

Processor is use to process data from receiver. Processed data on this component cosists of filtering, renaming, or recalculating. We could not only define processor once, but also multiple of them, depending on our needs. Outcome of telemetry data depends on sequence or order of data processing on this component. Here is example of processor definition

processors: # Data sources: traces attributes: actions: - key: environment value: production action: insert - key: db.statement action: delete - key: email action: hash # Data sources: traces, metrics, logs batch: # Data sources: metrics, metrics, logs filter: error_mode: ignore traces: span: - 'attributes["container.name"] == "app_container_1"' - 'resource.attributes["host.name"] == "localhost"' - 'name == "app_3"' spanevent: - 'attributes["grpc"] == true' - 'IsMatch(name, ".*grpc.*")' metrics: metric: - 'name == "my.metric" and resource.attributes["my_label"] == "abc123"' - 'type == METRIC_DATA_TYPE_HISTOGRAM' datapoint: - 'metric.type == METRIC_DATA_TYPE_SUMMARY' - 'resource.attributes["service.name"] == "my_service_name"' logs: log_record: - 'IsMatch(body, ".*password.*")' - 'severity_number < SEVERITY_NUMBER_WARN' # Data sources: traces, metrics, logs memory_limiter: check_interval: 5s limit_mib: 4000 spike_limit_mib: 500 # Data sources: traces resource: attributes: - key: cloud.zone value: zone-1 action: upsert - key: k8s.cluster.name from_attribute: k8s-cluster action: insert - key: redundant-attribute action: delete # Data sources: traces probabilistic_sampler: hash_seed: 22 sampling_percentage: 15 # Data sources: traces span: name: to_attributes: rules: - ^\/api\/v1\/document\/(?P<documentId>.*)\/update$ from_attributes: [db.svc, operation] separator: '::'
Enter fullscreen mode Exit fullscreen mode
  1. Exporter

Exporter is component that aims to export telemetry data that has been processed to other backend processes such as Jaeger, Zipkin, Prometheus, or Kafka. Each key on exporter use type/name format, where type defines kind of exporter like Jaeger, Kafka, or OpenTelemetry, and name is an optional field to seperate exporter that has same type. Here is an example of exporter.

exporters: # Data sources: traces, metrics, logs file: path: ./filename.json # Data sources: traces otlp/jaeger: endpoint: jaeger-server:4317 tls: cert_file: cert.pem key_file: cert-key.pem # Data sources: traces, metrics, logs kafka: protocol_version: 2.0.0 # Data sources: traces, metrics, logs # NOTE: Prior to v0.86.0 use `logging` instead of `debug` debug: verbosity: detailed # Data sources: traces, metrics opencensus: endpoint: otelcol2:55678 # Data sources: traces, metrics, logs otlp: endpoint: otelcol2:4317 tls: cert_file: cert.pem key_file: cert-key.pem # Data sources: traces, metrics otlphttp: endpoint: https://otlp.example.com:4318 # Data sources: metrics prometheus: endpoint: 0.0.0.0:8889 namespace: default # Data sources: metrics prometheusremotewrite: endpoint: http://prometheus.example.com:9411/api/prom/push # When using the official Prometheus (running via Docker) # endpoint: 'http://prometheus:9090/api/v1/write', add: # tls: # insecure: true # Data sources: traces zipkin: endpoint: http://zipkin.example.com:9411/api/v2/spans
Enter fullscreen mode Exit fullscreen mode

Instrumenting Go Application With OpenTelemetry Tracing

Spin Up Collector

Trace and span data emitted by server will be collected, stored, filtered, and exported by OpenTelemetry collector. The rules of collector defined by a configuration file as shown below.

receivers: otlp: protocols: grpc: endpoint: 0.0.0.0:4317 http: endpoint: 0.0.0.0:4318 processors: batch: exporters: otlphttp/trace: endpoint: http://tempo:4318 tls: insecure: true service: pipelines: traces: receivers: [otlp] processors: [batch] exporters: [otlphttp/trace]
Enter fullscreen mode Exit fullscreen mode

OpenTelemetry collector will collects all emmited traces and spans as mentioned at receivers.otlp.http.endpoint field. Value of this field is 0.0.0.0:4318 where 0.0.0.0 means the collector will listen to all IPv4 addresses.

After traces and spans has been collected by receiver, then they will be processed on processor. In this example, the data will be processed as batch.

Processed data then will be exported to trace visualization technology such as Grafana Tempo. Exporters are defined on exporters section.

Finally, we compile collecting, processing, and exporting traces data on service field.

Defining Exporter

Exporter on code level aims to connect application with collector. NewTracer function below explains exporter creation and connects created exporter with collector.

package trace import ( "context" "fmt" "net/http" "runtime" "time" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/trace" "go.opentelemetry.io/otel/attribute" "go.opentelemetry.io/otel/exporters/otlp/otlptrace" "go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracehttp" "go.opentelemetry.io/otel/propagation" "go.opentelemetry.io/otel/sdk/resource" traceSdk "go.opentelemetry.io/otel/sdk/trace" ) var globalServiceName string func NewTracer( ctx context.Context, serviceName string, ) error { propagator := propagation.NewCompositeTextMapPropagator( propagation.TraceContext{}, propagation.Baggage{}, ) otel.SetTextMapPropagator(propagator) // Create OpenTelemetry tracing client that exports // trace data to OpenTelemetry HTTP receiver traceClientHTTP := otlptracehttp.NewClient( otlptracehttp.WithInsecure(), ) traceExporter, err := otlptrace.New( ctx, traceClientHTTP, ) if err != nil { return err } res, err := resource.New( ctx, resource.WithContainer(), resource.WithFromEnv(), ) if err != nil { return err } tracerProvider := traceSdk.NewTracerProvider( traceSdk.WithBatcher( traceExporter, traceSdk.WithBatchTimeout(time.Second), ), traceSdk.WithResource( res, ), ) globalServiceName = serviceName otel.SetTracerProvider(tracerProvider) return nil }
Enter fullscreen mode Exit fullscreen mode

Define Tracing Components

In this article, we are going to record events on HTTP request and business logic/service by creating trace and generate span from each component. HTTPLevelSpan to trace over HTTP handler, while ServiceLevelSpan to trace over service level.

package trace import ( "context" "fmt" "net/http" "runtime" "time" "go.opentelemetry.io/otel" "go.opentelemetry.io/otel/trace" "go.opentelemetry.io/otel/attribute" ) func HTTPLevelSpan( ctx context.Context, r *http.Request, ) (context.Context, trace.Span) { spanName := fmt.Sprintf("%s %s", r.Method, r.URL.String()) ctx, span := otel.Tracer(globalServiceName).Start(ctx, spanName) if span.IsRecording() { span.SetAttributes(attribute.String("http.request.method", r.Method)) span.SetAttributes(attribute.String("server.address", r.RemoteAddr)) span.SetAttributes(attribute.String("url.full", r.URL.String())) } return ctx, span } func ServiceLevelSpan( ctx context.Context, ) (context.Context, trace.Span) { pc := make([]uintptr, 10) runtime.Callers(2, pc) f := runtime.FuncForPC(pc[0]) ctx, span := otel.Tracer(globalServiceName).Start(ctx, f.Name()) if span.IsRecording() { span.SetAttributes(attribute.String("code.function.name", f.Name())) } return ctx, span }
Enter fullscreen mode Exit fullscreen mode

When conducting trace on any aspect of application like HTTP, service, GRPC, or database, it is recommended to follow Semantic Convention or semconv. Semantic convention give us meaningful information about generated trace and span. Based on code above, code.function, server.address, and url.full are examples of semantic convention.

Instrumenting Application

Code below demonstrate usages of HTTPLevelSpan and ServiceLevelSpan

package server import ( "log" "net/http" ) func RunServer() { http.HandleFunc("/", home()) if err := http.ListenAndServe(":9320", nil); err != nil { log.Fatalf("could not start server: %v\n", err) } }
Enter fullscreen mode Exit fullscreen mode 
package server import ( "fmt" "log" "net/http" "strconv" "time" "go-trace-demo/service" "go-trace-demo/utils/metrics" utilsTrace "go-trace-demo/utils/trace" ) func home() http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { ctx := r.Context() ctx, span := utilsTrace.HTTPLevelSpan(ctx, r) defer span.End() respCode := 200 failQuery := r.URL.Query().Get("fail") if failQuery != "" { respCode = 500 isFail, err := strconv.ParseBool(failQuery) if err != nil { w.WriteHeader(http.StatusInternalServerError) w.Write([]byte("error parse query")) return } if isFail { w.WriteHeader(http.StatusInternalServerError) w.Write([]byte("encounter fail")) return } } err := service.GetUserByID(ctx) if err != nil { return } err = service.ListStores(ctx) if err != nil { return } w.Write([]byte("Hello, World!")) } }
Enter fullscreen mode Exit fullscreen mode 
package service import ( "context" utilsTrace "go-trace-demo/utils/trace" ) func GetUserByID( ctx context.Context, ) error { ctx, span := utilsTrace.ServiceLevelSpan(ctx) defer span.End() return nil } func ListStores( ctx context.Context, ) error { ctx, span := utilsTrace.ServiceLevelSpan(ctx) defer span.End() return nil }
Enter fullscreen mode Exit fullscreen mode

Below is main code

func main() { ctx := context.Background() serviceName := os.Getenv("OTEL_EXPORTER_OTLP_ENDPOINT") err := utilsTrace.NewTracer(ctx, serviceName) if err != nil { log.Fatalln("fail setup tracer") } server.RunServer() }
Enter fullscreen mode Exit fullscreen mode

Glue Everything

We'll run application, OpenTelemetry Collector, and Grafana Tempo using docker compose file below

version: "3" networks: observability: services: tempo: image: grafana/tempo:main-c5323bf command: [ "-config.file=/etc/tempo.yaml" ] volumes: - ./config/tempo-config.yaml:/etc/tempo.yaml - ./config/tempo-data:/var/tempo ports: - "3200:3200" # tempo - "4317" # open this port for OpenTelemetry gRPC exporter - "4318" # open this port for OpenTelemetry HTTP exporter networks: - observability otel-collector: image: otel/opentelemetry-collector:latest volumes: - ./config/otel-config.yaml:/etc/otel/config.yaml command: - '--config=/etc/otel/config.yaml' ports: - "4317:4317" #grpc - "4318:4318" #http depends_on: - loki networks: - observability app: container_name: app build: context: ./ dockerfile: ./Dockerfile ports: - 9320:9320 networks: - observability depends_on: - otel-collector environment: - OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector:4318 - OTEL_SERVICE_NAME=go-loki-app-demo grafana: environment: - GF_PATHS_PROVISIONING=/etc/grafana/provisioning - GF_AUTH_ANONYMOUS_ENABLED=true - GF_AUTH_ANONYMOUS_ORG_ROLE=Admin entrypoint: - sh - -euc - | mkdir -p /etc/grafana/provisioning/datasources cat <<EOF > /etc/grafana/provisioning/datasources/ds.yaml apiVersion: 1 datasources: - name: Loki type: loki access: proxy  orgId: 1 url: http://loki:3100 basicAuth: false isDefault: true version: 1 editable: false - name: Tempo type: tempo access: proxy  orgId: 1 url: http://tempo:3200 basicAuth: false version: 1 editable: false EOF /run.sh image: grafana/grafana:latest ports: - "3000:3000" networks: - observability
Enter fullscreen mode Exit fullscreen mode

Our application defined at service.app section. Be aware that we define OTEL_EXPORTER_OTLP_ENDPOINT environment variables for application. The reason is when we are defining OpenTelemetry HTTP exporter, we don't specify OpenTelemetry collector address. OpenTelemetry will look for OTEL_EXPORTER_OTLP_ENDPOINT environment variable to know where application should send trace data. If you have specific OpenTelemetry exporter, you can use WithEndpointURL argument for otlptracehttp.NewClient. Additionally, we define OTEL_SERVICE_NAME environment variable where the purpose is for OpenTelemetry identify what service they are receive the trace data. If OTEL_SERVICE_NAME not provided, OpenTelemetry will fill with unknown_service value.

Visualizing Traces Using Grafana Tempo

After successful container creation with Docker compose, let's generate trace data by accessing localhost:9320/. Next, access Grafana on localhost:3000, then head to Exlpore menu by click dropdown menu on top left corner.
alt text

Switch to Search query type instead of TraceQL, then click Service Name dropdown. It will show service name we provided on OTEL_SERVICE_NAME
alt text. By click Run Query, we'll have something like this.
alt text

Explore trace data by click available row on Trace column. We will be redirected to trace detail like this
alt text.

Additionally, explore span attribute by click one of span. We will see span attribute and resource attribute we defined when we are creating OpenTelemetry trace instance.

References

Top comments (0)