5.4 신속하고 간단하게 o11y 적용하기

개인적으로 데이터독을 사용해서 프로젝트를 수행했습니다만, 향후 관찰가능성의 대세는 오픈소스가 될것이라는 점에 대해서는 의심의 여지가 없습니다.

오픈소스 기반의 관찰가능성

오픈소스의 단점은 상용만큼 기술지원이 안 되기 때문에, 러닝커브가 상대적으로 높습니다. 하지만 상용도 복잡하고, 자료가 정확히 전달이 안되는 것은 마찬가지라고 생각됩니다. 시간이 지날수록 엔지니어의 실력이 향상될수록 상용은 한계에 부딪치게 됩니다.

상용과 오픈소스의 갈림길에서, 오픈텔레메트리는 앞으로의 방향성을 확실히 제시하고 있습니다.

계측의 문제점

실제로 오픈텔레메트리 도입이 간단하지 않습니다. 가장 큰 이유는 레거시가 존재하기 때문입니다.

  1. 레거시 모니터링 시스템에 설치된 에이전트를 대체해야 합니다.
  2. 기존 레거시 API를 제거하고, 오픈텔레메트리 API로 변경해야 합니다.

기존 레거시를 잘 활용하고 있는 상황이라면, 새로운 오픈텔레메트리와 관찰가능성의 도입은 많은 시간과 비용을 필요로 하는 어려운 작업입니다.

현업에서는 수동 계측보다는 자동 계측을 많이 사용합니다. 수동 계측을 사용하면 문맥을 풍부하게 만들고, 근본 원인 분석이 더 용이하도록 만들 수 있는 장점도 있습니다.

하지만 수동 계측은 소스 수정을 필요로 하므로, 개발자의 반발도 있고 높은 비용을 수반하는 작업임에는 틀림없습니다.

특히 인프라가 아니라 어플리케이션이 중요한 경우라면 수동 계측의 의미를 부여할 수 있습니다. 자동 계측은 분명 한계가 있기 때문입니다. 이 글에서 소개하는 메트릭 생성기도 여러 가지 제약 사항이 있습니다.

최소한의 비용과 최단 기간에 오픈텔레메트리를 도입한다는 가정 하에 글을 써 보고자 합니다.

이번 글에 사용되는 어플리케이션은 아래와 같은 특징을 가지고 있습니다.

  1. Loki, Prometheus, Tempo로 구성됩니다.
  2. Go로 개발되었으며, 서버에서 메트릭, 로그, 추적을 생성합니다.

간단한 어플리케이션이고, 관찰가능성을 설명하는데 유용합니다.

구성 절차

일반적으로 관찰가능성을 데모하는 절차는 아래와 같습니다.

  1. Exemplar를 사용해서, 메트릭과 추적을 연계합니다.
  2. 이전 데모에서는 Span metrics를 사용했지만, 이번에는 커스텀 메트릭을 사용합니다. 예를 들어 demo_request_latency_seconds_bucket 을 사용할 것입니다.
  3. 수집된 로그에서 traceID를 추출하고, 로그와 추적을 연계합니다.

이전 데모와는 다른 방식으로 관찰가능성을 구현하도록 하겠습니다.

위의 3가지 절차만 구성해도 메트릭, 로그, 추적 간에 쉽게 연계하실 수 있습니다. 시간과 비용을 절감할 수 있는 효과적인 방법입니다.

프로메테우스 구성파일과 템포의 구성파일은 이전 데모와 거의 유사합니다.

템포 구성파일입니다. 매트릭 생성기가 제외되었습니다.

multitenancy_enabled: false
search_enabled: true

server:
http_listen_port: 3200

distributor:
receivers:
jaeger:
protocols:
thrift_http:
grpc:
thrift_binary:
thrift_compact:
zipkin:
otlp:
protocols:
http:
grpc:

storage:
trace:
backend: local
local:
path: /tmp/tempo/blocks

백엔드 어플리케이션에 요청합니다.

philip@philip-virtual-machine:~$ curl http://localhost:8000/

자동화하는 경우에는 아래처럼 실행합니다.

while true; do curl http://localhost:8000/; sleep 2; clear; done

추적을 생성합니다. 로그에 표시된 latency는 이상탐지를 테스트하기 위한 좋은 예입니다. sleep을 0.1로 정의하면 latency 가 급격히 증가하는 경우가 있을 것입니다. 이상탐지는 이러한 지연을 탐지하고, 원인 분석을 할 수 있습니다.

listening...
ts=2022-12-08T09:00:31.927275998Z msg="http request" traceID=a7d5fad55e0f1a68b21705b1b6988bb8 path=/ latency=102.121289ms
hello world
hello world
ts=2022-12-08T09:00:32.03030602Z msg="http request" traceID=a7d5fad55e0f1a68b21705b1b6988bb8 path=/ latency=101.204696ms
hello world
ts=2022-12-08T09:00:32.030811861Z msg="http request" traceID=a7d5fad55e0f1a68b21705b1b6988bb8 path=/ latency=309.020192ms
hello world
ts=2022-12-08T09:00:32.031244984Z msg="http request" traceID=a7d5fad55e0f1a68b21705b1b6988bb8 path=/ latency=414.046547ms
hello world
ts=2022-12-08T09:00:32.031742669Z msg="http request" traceID=a7d5fad55e0f1a68b21705b1b6988bb8 path=/ latency=517.627752ms

위에서 결과처럼 로그의 형식은 아래와 같습니다.

ts=2023–01–12T05:43:30.689033161Z msg="http request" traceID=cb752735fbb4e8a7db8852e7611f929e path=/ latency=101.490632ms

오픈 메트릭을 요청합니다.

philip@philip-virtual-machine:~$ curl -H 'Accept: application/openmetrics-text' http://localhost:8000/metrics | less

오픈 메트릭을 확인합니다. traceID 가 출력되는 것을 보실 수 있습니다 이전에도 설명드렸던 exemplar 입니다.

# HELP demo_request_latency_seconds Request Latency
# TYPE demo_request_latency_seconds histogram
demo_request_latency_seconds_bucket{le="0.0001"} 0
demo_request_latency_seconds_bucket{le="0.0002"} 0
demo_request_latency_seconds_bucket{le="0.0004"} 0
demo_request_latency_seconds_bucket{le="0.0008"} 0
demo_request_latency_seconds_bucket{le="0.0016"} 0
demo_request_latency_seconds_bucket{le="0.0032"} 0
demo_request_latency_seconds_bucket{le="0.0064"} 0
demo_request_latency_seconds_bucket{le="0.0128"} 0
demo_request_latency_seconds_bucket{le="0.0256"} 0
demo_request_latency_seconds_bucket{le="0.0512"} 0
demo_request_latency_seconds_bucket{le="0.1024"} 2 # {traceID="a7d5fad55e0f1a68b21705b1b6988bb8"} 0.101191218 1.670490032030292e+09
demo_request_latency_seconds_bucket{le="0.2048"} 2
demo_request_latency_seconds_bucket{le="0.4096"} 3 # {traceID="a7d5fad55e0f1a68b21705b1b6988bb8"} 0.309012213 1.6704900320308034e+09
demo_request_latency_seconds_bucket{le="0.8192"} 5 # {traceID="a7d5fad55e0f1a68b21705b1b6988bb8"} 0.517619484 1.670490032031735e+09
demo_request_latency_seconds_bucket{le="1.6384"} 5
demo_request_latency_seconds_bucket{le="3.2768"} 5
demo_request_latency_seconds_bucket{le="6.5536"} 5
demo_request_latency_seconds_bucket{le="13.1072"} 5
demo_request_latency_seconds_bucket{le="26.2144"} 5
demo_request_latency_seconds_bucket{le="52.4288"} 5
demo_request_latency_seconds_bucket{le="104.8576"} 5
demo_request_latency_seconds_bucket{le="209.7152"} 5
demo_request_latency_seconds_bucket{le="419.4304"} 5
demo_request_latency_seconds_bucket{le="838.8608"} 5
demo_request_latency_seconds_bucket{le="1677.7216"} 5
demo_request_latency_seconds_bucket{le="3355.4432"} 5
demo_request_latency_seconds_bucket{le="6710.8864"} 5
demo_request_latency_seconds_bucket{le="13421.7728"} 5
demo_request_latency_seconds_bucket{le="26843.5456"} 5
demo_request_latency_seconds_bucket{le="53687.0912"} 5
demo_request_latency_seconds_bucket{le="107374.1824"} 5
demo_request_latency_seconds_bucket{le="214748.3648"} 5
demo_request_latency_seconds_bucket{le="429496.7296"} 5
demo_request_latency_seconds_bucket{le="858993.4592"} 5
demo_request_latency_seconds_bucket{le="1.7179869184e+06"} 5
demo_request_latency_seconds_bucket{le="3.4359738368e+06"} 5
demo_request_latency_seconds_bucket{le="6.8719476736e+06"} 5
demo_request_latency_seconds_bucket{le="1.37438953472e+07"} 5
demo_request_latency_seconds_bucket{le="2.74877906944e+07"} 5
demo_request_latency_seconds_bucket{le="5.49755813888e+07"} 5

이번에 데모하는 어플리케이션은 마이크로서비스가 1개입니다. 관찰가능성의 모든 기능을 데모하기 위해서, 1개 마이크로서비스만으로도 충분합니다.

어플리케이션을 설치하고 구성하는 방법은 이전 데모와 유사하기 때문에 설명하지 않습니다. 이 글에서는 화면 중심으로 더 설명하겠습니다.

신호를 이해하는 방법

초 당 호출 개수를 변경하면서, 트랜잭션을 자동적으로 생성합니다. 1시간 동안 아래와 같은 메트릭을 생성합니다.

가장 오랫동안 지연이 발생하는 트랜잭션을 선택하고, exemplar를 클릭하면 아래와 같은 화면을 볼 수 있습니다.

추적으로 이동할 수 있는 버튼이 활성화됩니다.

버튼을 클릭하면, 오른쪽에 일치되는 추적이 활성화됩니다.

지연이 발생한 근본원인을 분석하기 위해서, span을 클릭합니다.

운영 시에는 다양한 관점에서, 다양한 방법으로 시스템을 이해하고 분석합니다. 툴은 이러한 목적을 달성하기 위한 수단이며, 다양한 기능을 제공해줘야 합니다.

이번에는 로그부터 시작해 봅시다.

로그 화면에서 빌더를 사용해서, 로그를 조회하는 쿼리를 쉽게 생성할 수 있습니다.

로그 발생 개수를 시간 순서대로 출력하고 있습니다.

상세한 추적으로 이동할 수 있도록, 버튼을 제공합니다.

오른쪽 화면에 추적을 출력합니다.

오픈텔레메트리와 연계

소개드린 데모에 오픈텔레메트리 컬렉터를 사용하지 않습니다. 하지만 우리는 언제든 오픈텔레메트리 컬렉터를 중간에 추가할 수 있습니다. 컬렉터를 추가함으로써 향후 안정적으로 텔레메트리 표준인 오픈텔레메트리로 연계할 수 있는 방법을 제공합니다.

아래는 소스입니다.

package main

import (
"context"
"fmt"
"math/rand"
"net/http"
"os"
"time"

"google.golang.org/grpc"

"github.com/go-kit/kit/log"
"github.com/gorilla/mux"
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
"github.com/prometheus/client_golang/prometheus/promhttp"
"go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp"
"go.opentelemetry.io/otel"
"go.opentelemetry.io/otel/exporters/otlp"
"go.opentelemetry.io/otel/exporters/otlp/otlpgrpc"
"go.opentelemetry.io/otel/propagation"
"go.opentelemetry.io/otel/sdk/resource"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
"go.opentelemetry.io/otel/semconv"
"go.opentelemetry.io/otel/trace"
)

// global vars...gasp!
var addr = "127.0.0.1:8000"
var tracer trace.Tracer
var httpClient http.Client
var logger log.Logger

var metricRequestLatency = promauto.NewHistogram(prometheus.HistogramOpts{
Namespace: "demo",
Name: "request_latency_seconds",
Help: "Request Latency",
Buckets: prometheus.ExponentialBuckets(.0001, 2, 50),
})

func main() {
flush := initTracer()
defer flush()

// initiate globals
tracer = otel.Tracer("demo-app")
httpClient = http.Client{Transport: otelhttp.NewTransport(http.DefaultTransport)}
logger = log.NewLogfmtLogger(log.NewSyncWriter(os.Stdout))
logger = log.With(logger, "ts", log.DefaultTimestampUTC)

// create and start server
server := instrumentedServer(handler)

fmt.Println("listening...")
server.ListenAndServe()
}

func handler(w http.ResponseWriter, r *http.Request) {
ctx := r.Context()

longRunningProcess(ctx)

// check cache
if shouldExecute(40) {
url := "http://" + addr + "/"

resp, err := instrumentedGet(ctx, url)
defer resp.Body.Close()
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
}
}

// query database
if shouldExecute(40) {
url := "http://" + addr + "/"

resp, err := instrumentedGet(ctx, url)
defer resp.Body.Close()
if err != nil {
http.Error(w, err.Error(), http.StatusInternalServerError)
}
}
}

func shouldExecute(percent int) bool {
return rand.Int()%100 < percent
}

func longRunningProcess(ctx context.Context) {
ctx, sp := tracer.Start(ctx, "Long Running Process")
defer sp.End()

time.Sleep(time.Millisecond * 50)
sp.AddEvent("halfway done!")
time.Sleep(time.Millisecond * 50)
}

/***
Tracing
***/
// Initializes an OTLP exporter, and configures the trace provider
func initTracer() func() {
ctx := context.Background()

driver := otlpgrpc.NewDriver(
otlpgrpc.WithInsecure(),
otlpgrpc.WithEndpoint("tempo:55680"),
otlpgrpc.WithDialOption(grpc.WithBlock()), // useful for testing
)
exp, err := otlp.NewExporter(ctx, driver)
handleErr(err, "failed to create exporter")

res, err := resource.New(ctx,
resource.WithAttributes(
// the service name used to display traces in backends
semconv.ServiceNameKey.String("demo-service"),
),
)
handleErr(err, "failed to create resource")

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

// set global propagator to tracecontext (the default is no-op).
otel.SetTextMapPropagator(propagation.TraceContext{})
otel.SetTracerProvider(tracerProvider)

return func() {
// Shutdown will flush any remaining spans.
handleErr(tracerProvider.Shutdown(ctx), "failed to shutdown TracerProvider")
}
}

/***
Server
***/
func instrumentedServer(handler http.HandlerFunc) *http.Server {
// OpenMetrics handler : metrics and exemplars
omHandleFunc := func(w http.ResponseWriter, r *http.Request) {
start := time.Now()

handler.ServeHTTP(w, r)

ctx := r.Context()
traceID := trace.SpanContextFromContext(ctx).TraceID.String()

metricRequestLatency.(prometheus.ExemplarObserver).ObserveWithExemplar(
time.Since(start).Seconds(), prometheus.Labels{"traceID": traceID},
)

// log the trace id with other fields so we can discover traces through logs
logger.Log("msg", "http request", "traceID", traceID, "path", r.URL.Path, "latency", time.Since(start))
}

// OTel handler : traces
otelHandler := otelhttp.NewHandler(http.HandlerFunc(omHandleFunc), "http")

r := mux.NewRouter()
r.Handle("/", otelHandler)
r.Handle("/metrics", promhttp.HandlerFor(prometheus.DefaultGatherer, promhttp.HandlerOpts{
EnableOpenMetrics: true,
}))

return &http.Server{
Handler: r,
Addr: "0.0.0.0:8000",
}
}

/***
Client
***/
func instrumentedGet(ctx context.Context, url string) (*http.Response, error) {
// create http request
req, err := http.NewRequestWithContext(ctx, "GET", url, nil)
if err != nil {
panic(err)
}

return httpClient.Do(req)
}

func handleErr(err error, message string) {
if err != nil {
panic(fmt.Sprintf("%s: %s", err, message))
}
}

--

--

모니터링의 새로운 미래 관측 가능성

모니터링의 새로운 미래 관측 가능성의 소스를 설명합니다.