První krůčky s Grafana Cloud a OpenTelemetry

V pátek (nebo spíš v sobotu) jsem psal, že si chci vyzkoušet OpenTelemetry s Grafana Cloudem, kde je nyní možnost využívat Tempo pro sbírání traces. Dnes tady nebudu vysvětlovat, proč chcete v aplikaci dělat tracing. Na internetu je k tomu docela dost zdrojů a já takhle při večeru nechci vést filozofické monology. 

Takže zpět ke Grafana. Něco z mých plánů se již povedlo, a tak se chci podělit o svůj výzkum. Není to žádná raketová věda a můj kód je trochu zprasený, i tak by to ale mohlo někomu pomoci, až bude chtít začit s drobnou instrumentací kódu (což bych doporučoval).

Kód budu jako obvykle psát v Go. Ale vlastně to není vůbec podstatná informace, protože OpenTelemetry knihovny vypadají ve všech jazycích velmi podobně.

Grafana agent

Vše, co jsem pro své experimenty potřeboval, je obsaženo v Grafana Agent, který je momentálně v beta fázi. Je to relativně malá binárka, která má následující funkce:

  • logging agent
  • agent pro sbírání (scrapování metrik)
  • kolektor pro Tempo (sem se sypou spany pro tracing)

Základní konfigurace pro tracing se vejde na pár řádků a vypadá nějak takhle:

tempo:
  push_config:
    endpoint: tempo-us-central1.grafana.net:443
    basic_auth:
      username: <User ID Grafana účtu>
      password: <API klíč z Grafana účtu>
  receivers:
    otlp:
      protocols:
        http:
        grpc:

Pozor, každá služba má jiné credentials (alespoň k takovému závěru jsem dospěl), takže se nesnažte cpát credentials pro Prometheus backend do Tempo a naopak.

Pak hned můžeme agenta spustit.

./agent-darwin-amd64 --config.file=agent-config.yaml

V jeho logu se pak můžete podívat, kde OpenTelemetry kolektory poslouchají.

ts=2021-01-16T15:54:13Z level=info msg="Receiver is starting..." component=tempo component_kind=receiver component_type=otlp component_name=otlp
ts=2021-01-16T15:54:13Z level=info msg="Starting GRPC server on endpoint 0.0.0.0:4317" component=tempo component_kind=receiver component_type=otlp component_name=otlp
ts=2021-01-16T15:54:13Z level=info msg="Setting up a second GRPC listener on legacy endpoint 0.0.0.0:55680" component=tempo component_kind=receiver component_type=otlp component_name=otlp
ts=2021-01-16T15:54:13Z level=info msg="Starting GRPC server on endpoint 0.0.0.0:55680" component=tempo component_kind=receiver component_type=otlp component_name=otlp
ts=2021-01-16T15:54:13Z level=info msg="Starting HTTP server on endpoint 0.0.0.0:55681" component=tempo component_kind=receiver component_type=otlp component_name=otlp

Nás bude zajímat ten 4317, protože budeme komunikovat pomocí gRPC. 

Vytvoření Trace Provideru

Jednou z největších výhod OpenTelemetry je fakt, že nevytváří vendor lock-in na služby třetích stran. V zásadě každý vendor může připravit svůj exporter, který pak někde zapojíte do kódu a kdykoliv ho můžete vyměnit za jiný bez změn v aplikaci. Takhle nějak vypadá inicializace Trace Provideru s otlp exporterem, který v této ukázce budeme používat.

package otlp

import (
	"context"
	"fmt"

	"google.golang.org/grpc"

	"go.opentelemetry.io/otel/exporters/otlp"
	"go.opentelemetry.io/otel/exporters/otlp/otlpgrpc"
	"go.opentelemetry.io/otel/sdk/resource"
	sdktrace "go.opentelemetry.io/otel/sdk/trace"
	"go.opentelemetry.io/otel/semconv"
)

func InitTraceProvider(ctx context.Context, serviceName string, address string) (*sdktrace.TracerProvider, error) {
	driver := otlpgrpc.NewDriver(
		otlpgrpc.WithInsecure(),
		otlpgrpc.WithEndpoint(address),            // e.g. localhost:4317
		otlpgrpc.WithDialOption(grpc.WithBlock()), // useful for testing
	)
	exp, err := otlp.NewExporter(ctx, driver)
	if err != nil {
		return nil, fmt.Errorf("could not create exporter: %s", err)
	}

	res, err := resource.New(ctx,
		resource.WithAttributes(
			semconv.ServiceNameKey.String(serviceName),
		),
	)
	if err != nil {
		return nil, fmt.Errorf("could not create resoruce: %s", err)
	}

	bsp := sdktrace.NewBatchSpanProcessor(exp)
	return sdktrace.NewTracerProvider(
		sdktrace.WithConfig(sdktrace.Config{DefaultSampler: sdktrace.AlwaysSample()}),
		sdktrace.WithResource(res),
		sdktrace.WithSpanProcessor(bsp),
	), nil
}

PS nic z toho jsem v podstatě nepsal. Je to copy & paste ze všech možných ukázek. Mou jedinou invencí v tomto kódu je return na konci, protože nejsem zastánce černé magie, která by v tomto případě znamenala registrováni globálního Trace Provideru.

Instrumentace kódu

Když máme Trace Provider, tak si můžeme zkusit vytvořit nějaké spany. 

func main() {
	tp, err := otlp.InitTraceProvider(ctx, "backend", "localhost:4317")
	if err != nil {
		logger.Sugar().Panicf("could not initialize Trace Provider: %s", err)
	}

	_, span := tp.Tracer("jmeno/traceru").Start(ctx, "sleep")
	time.Sleep(time.Second*10)
    logger.Info(span.SpanContext().TraceID.String())
	span.End()
}

Trace ID, co nám vypadne z logu, si můžeme pak hodit do Grafana a uvidíme něco takového:

Skutečně to spalo 10 minut. Potrestám se za to, nebojte.

Korelace mezi logy a traces

Ale když chcete z nějaké problematické log zprávy přejít do tracingu a podívat se časovou osu událostí? Tohle je v podstatě gró celé "Observability" - spojit všechny části do kupy tak, aby to dávalo nějaký smysl. 

Konfiguraci loggingu v tomto článku nehledejte. Já použil Loki plugin pro Docker, ale tohle je zkrátka věc, která se budu lišit v závislosti na vašem dev stacku.

Řešení je v tomto případě naprosto jednoduché, do log zprávy vypíšeme Trace ID a pak se podíváme, jak nám může Grafana pomoci s tím, aby se to hezky používalo. Takže teď si do logu naprasíme novou property TraceID:

span := sdktrace.SpanFromContext(ctx)
logger.Sugar().Infow("nevím, co se napsat", "TraceID", span.SpanContext().TraceID.String())

A v Grafana dashboardu si najdeme logy (data source Loki).

Teď tady vidím, v jakém trace kontextu jsem ten log vytvořil, ale pro zobrazení grafu musím udělat copy & paste. To v důsledku povede k tomu, že tracing nikdo nebude používat, protože i dva kliky navíc jsou moc. Vyzkoušeno.

Naštěstí Grafana umí takzvané Derived Fields, díky kterým můžeme přímo do logu nacpat klikátko, které operátorovi nebo vývojáři otevře celý trace ve stejném okně. 

Když teď uložíme Loki Data Source a vrátíme se do přehledu logů, tak uvidíme následující výjev.

Grafana nám automaticky nalinkovala nějaký resource patřící pod Tempo data source. Když klikneme na modrý obdélníček, tak se před nám zjeví ucelený obraz zvěrstev, co se dějí v naší aplikaci.

Co dál?

Tohle je docela hustý, ale osobně bych u toho všeho chtěl vidět i nějaké metriky, které by mi ještě více pomohly pochopit celý kontext. Tuhle část jsem ještě nezkoušel a vlastně ani nevím, jestli to jde udělat. Jestli máte za sebou úspěšnou implementaci, tak budu strašně rád, když se podělíte o své zkušenosti.

Závěr

Tohle bylo dost jednoduché, ne? To nejlepší na tom je, že skutečnost je úplně stejně jednoduchá. Prostě naimportujete OpenTelemetry, vyberete si poskytovatele služeb (LightStep, Honeycomb, Grafana) a začnete aplikaci pomocí spanů sekat na nějaké dílčí kousky, které pak můžou vyprávět příběh.

A když jste si vybrali špatného poskytovatele, tak prostě vyměníte exporter a jedete dál. Osobně považuji OpenTelemetry za jeden z nejlepších projektů pod CNCF, právě pro jeho úžasnou přenositelnost.