Наблюдаемость начинается не с дашбордов, а с инструментирования. Пока сервис не отдаёт traces, metrics и logs в понятном формате, любой красивый экран Grafana — пустая коробка. OpenTelemetry задаёт единый способ порождать все три сигнала, но у него есть своя логика: что делает SDK, что API, где хватит автоматики, а где придётся расставлять спаны руками.
Это первая статья серии «Наблюдаемость на практике». Здесь разбираемся, как сигналы вообще попадают в стек — на примере Go-сервиса с SDK и JVM-приложения с агентом. Всё, что ниже, снято с живого стенда: пять спанов на запрос, замеры накладных расходов в двух повторах и опыт, в котором код с телеметрией работает, а телеметрия не уходит.
В статье
- API против SDK: почему это два разных пакета
- Стенд: что именно инструментируем
- Три сигнала и их разная зрелость
- Автоматика против ручного: что видно в трейсе
- Ресурсные атрибуты: кто это отправил
- Экспорт в Collector: gRPC против HTTP
- Сколько это стоит
- Логи: контекст решает всё
- Итог
- Документация и первоисточники
API против SDK: почему это два разных пакета
В OpenTelemetry разделены две вещи, которые в других системах слиты:
- API — то, что вызывает код: создать спан, увеличить счётчик, записать событие. По умолчанию все реализации API — «пустышки» (no-op), они ничего не делают и почти ничего не стоят.
- SDK — реализация: сэмплирование, батчинг, экспортёры, ресурсные атрибуты. Подключается один раз, на старте приложения.
Разделение существует ради библиотек. Библиотека зависит только от API и потому не тянет за собой ваш выбор бэкенда, сэмплера и транспорта. Решение принимает приложение — тем, что инициализирует SDK.
У этого разделения есть следствие, которое стоит увидеть живьём, а не прочитать: приложение с инструментированным кодом, но без инициализированного SDK, работает совершенно нормально и не отдаёт ничего. Ничего не падает, в логах нет ошибок — просто в бэкендах пусто.
В стенде это проверяется переключателем режима. У Go выставляется штатная переменная OTEL_SDK_DISABLED=true, у Java просто не подключается -javaagent. Код приложения при этом не меняется — те же вызовы трассера и счётчика остаются на месте:
план: всего=120, 201=105, 404=10, 502=5, ошибок=15
прогон: 120 запросов за 612ms, параллельно 4
201: ожидалось 105, получено 105
404: ожидалось 10, получено 10
502: ожидалось 5, получено 5
итог: факт совпал с планом
трейсы с меткой прогона в Tempo: 0
khorost_tech_orders_created_total до прогона: 275
khorost_tech_orders_created_total после: 275
лог самого приложения: {"msg":"режим телеметрии","sdk_enabled":false}Приложение обслужило все 120 запросов и вернуло ровно то, что должно было. Сигналов при этом нет ни одного. Именно поэтому «пустые дашборды» ищут долго: искать нечего, ошибок нет, всё «работает».
Проверка на стороне кода выглядит так — и обратите внимание, что пропагаторы ставятся всегда, даже когда SDK выключен: они относятся к API и без них не будет проброса контекста между сервисами.
// Пропагаторы ставятся ВСЕГДА, даже при выключенном SDK: они относятся к API
// и стоят копейки. Без них не будет проброса контекста между сервисами.
otel.SetTextMapPropagator(propagation.NewCompositeTextMapPropagator(
propagation.TraceContext{},
propagation.Baggage{},
))
if !SDKEnabled() {
return t, nil
}Стенд: что именно инструментируем
Подопытная система намеренно скучная и намеренно разнородная: HTTP-вход на Go, вызов Java-сервиса, запрос в PostgreSQL через JDBC, асинхронное событие через NATS. Разнородность здесь и есть смысл — она даёт разные границы, на которых теряется контекст.
детерминированный сценарий] --> GF subgraph app["подопытная система"] GF["go-frontend
Go SDK + otelhttp"] JB["java-backend
агент -javaagent"] PG[(PostgreSQL)] NATS{{NATS}} GF -->|HTTP| JB GF -->|событие| NATS NATS --> JB JB -->|JDBC| PG end GF -->|"OTLP gRPC 4317"| COL JB -->|"OTLP HTTP 4318"| COL subgraph obs["стек наблюдаемости"] COL["OTel Collector"] TEMPO[("Tempo
трейсы")] LOKI[("Loki
логи")] PROM[("Prometheus
метрики")] COL -->|трейсы| TEMPO COL -->|логи| LOKI COL -->|"скрейп 8889"| PROM TEMPO --> GRAF["Grafana"] LOKI --> GRAF PROM --> GRAF end
flowchart LR
LG[loadgen
детерминированный сценарий] --> GF
subgraph app["подопытная система"]
GF["go-frontend
Go SDK + otelhttp"]
JB["java-backend
агент -javaagent"]
PG[(PostgreSQL)]
NATS{{NATS}}
GF -->|HTTP| JB
GF -->|событие| NATS
NATS --> JB
JB -->|JDBC| PG
end
GF -->|"OTLP gRPC 4317"| COL
JB -->|"OTLP HTTP 4318"| COL
subgraph obs["стек наблюдаемости"]
COL["OTel Collector"]
TEMPO[("Tempo
трейсы")]
LOKI[("Loki
логи")]
PROM[("Prometheus
метрики")]
COL -->|трейсы| TEMPO
COL -->|логи| LOKI
COL -->|"скрейп 8889"| PROM
TEMPO --> GRAF["Grafana"]
LOKI --> GRAF
PROM --> GRAF
end
Стенд — digital-cookbook/observability/practice-stack. Версии зафиксированы и сверены с тем, что сообщает о себе сам бинарник: OTel Collector contrib 0.158.0, Tempo 3.0.2, Loki 3.7.5, Prometheus 3.13.2, Grafana 13.1.2, PostgreSQL 18.4, NATS 2.14.4, Go SDK v1.45.0, Java-агент 2.30.0.
Приложения ничего не знают о Tempo, Loki и Prometheus: они говорят только OTLP в Collector, а он разводит три сигнала по трём бэкендам. Зачем нужен Collector и какие у него есть режимы развёртывания — в отдельной статье; здесь он просто стоит на входе.
Одна деталь стенда важна для дальнейшего. Медленный путь — запрос по SKU-0004 — сделан через pg_sleep(0.15) внутри SQL-запроса, а не через Thread.sleep в приложении:
String sql = SLOW_SKU.equals(sku)
? "SELECT sku, name, quantity, pg_sleep(0.15) FROM inventory WHERE sku = ?"
: "SELECT sku, name, quantity FROM inventory WHERE sku = ?";Разница принципиальна: в трейсе должно быть видно, что время потрачено в базе. Задержка в приложении выглядела бы иначе, и вывод «узкое место — БД» оказался бы подделкой.
Заодно этот фрагмент — памятник неудачной первой редакции. В ней pg_sleep стоял в WHERE: AND pg_sleep(0.15) IS NULL. Функция возвращает void, условие не выполнялось, запрос возвращал ноль строк, и сервис честно отвечал 404 на существующий товар. Поймалось это не глазами, а сверкой факта с планом нагрузки: генератор ожидал 186 ответов 201, получил 165, а 21 запрос ушёл в 404. Без точного ожидания «медленный путь работает» выглядел бы правдой.
Три сигнала и их разная зрелость
Traces, metrics и logs в OpenTelemetry устроены единообразно: провайдер, экспортёр, процессор, общий ресурс. В документации они выглядят как три равные части одного целого. На практике они равны не вполне, и это стоит знать до того, как закладывать их в прод.
В Go SDK на момент написания:
| Сигнал | Модуль | Версия |
|---|---|---|
| Трейсы | go.opentelemetry.io/otel/sdk |
v1.45.0 |
| Метрики | go.opentelemetry.io/otel/sdk/metric |
v1.45.0 |
| Логи | go.opentelemetry.io/otel/sdk/log |
v0.21.0 |
| Экспортёр логов | .../exporters/otlp/otlplog/otlploggrpc |
v0.21.0 |
| Мост slog | go.opentelemetry.io/contrib/bridges/otelslog |
v0.20.0 |
Трейсы и метрики давно стабильны, логовая часть — всё ещё нулевой мажор. Это не значит «не работает»: в стенде логи через OTLP доезжают до Loki и корректно связываются с трейсами. Это значит «интерфейс может измениться», и на обновлении вас может ждать правка кода.
Инициализация всех трёх выглядит однотипно. Порядок остановки при этом важен не меньше порядка создания:
func (t *Telemetry) Shutdown(ctx context.Context) error {
var errs error
// В обратном порядке: сначала то, что создано последним.
for i := len(t.shutdowns) - 1; i >= 0; i-- {
if err := t.shutdowns[i](ctx); err != nil {
errs = errors.Join(errs, err)
}
}
return errs
}Без корректного Shutdown теряется последняя пачка спанов и метрик — та самая, которая обычно и относится к интересному событию. Со стороны это выглядит как «телеметрия работает через раз».
Автоматика против ручного: что видно в трейсе
Вот полный трейс одного запроса по медленному пути. Пять спанов, два сервиса, и ручной здесь только один:
СЕРВИС СПАН ВИД ДЛИТ. ОТКУДА ВЗЯЛСЯ
go-frontend POST /order SERVER 156.8 мс otelhttp (обёртка Handler)
go-frontend create_order INTERNAL 156.7 мс РУЧНОЙ, код приложения
go-frontend HTTP GET CLIENT 156.6 мс otelhttp (обёртка Transport)
java-backend GET /inventory/{sku} SERVER 153.3 мс Java-агент, io.opentelemetry.tomcat-10.0
java-backend SELECT orders.inventory CLIENT 151.7 мс Java-агент, io.opentelemetry.jdbc151,7 мс из 156,8 — внутри запроса к базе. Это ровно то, ради чего трейсинг и нужен: видно не «сервис медленный», а «время в SQL».
В Go автоматика — это обёртки. Серверная сторона:
// otelhttp на входе даёт серверный спан и метрики HTTP автоматически, и он
// же ИЗВЛЕКАЕТ traceparent из заголовков — без этого запрос от внешнего
// клиента всегда начинал бы новый трейс.
handler := otelhttp.NewHandler(svc.Routes(), "http.server",
otelhttp.WithFilter(func(r *http.Request) bool {
// Проверки живости не нужны ни в трейсах, ни в метриках: они
// составляют большинство запросов и ничего не сообщают.
return r.URL.Path != "/health"
}),
)Клиентская отличается от неинструментированной одной строкой — обёрткой транспорта:
func newInstrumentedHTTPInventory(baseURL string, timeout time.Duration) *httpInventory {
return &httpInventory{
baseURL: baseURL,
client: &http.Client{
Timeout: timeout,
Transport: otelhttp.NewTransport(http.DefaultTransport),
},
}
}Эта строка делает две вещи разом: создаёт клиентский спан и инъектирует traceparent в заголовки. Что происходит без неё — тема следующей статьи серии.
В Java автоматика — это агент, и подключается он вне кода:
# Агент НЕ включается здесь: включение делается переменной JAVA_TOOL_OPTIONS в
# compose. Так один и тот же образ даёт и базовую линию без телеметрии, и
# вариант с агентом — иначе замер накладных расходов сравнивал бы разные образы.
ENTRYPOINT ["java", "-jar", "/app/app.jar"]write_env "-javaagent:/app/opentelemetry-javaagent.jar" "false" \
"http://otelcol:4317" "http://otelcol:4318" "grpc"В коде Java-сервиса нет ни строки про телеметрию — это проверяемое утверждение, и проверить его можно только если код действительно чист. Спаны Tomcat и JDBC из таблицы выше получены именно так.
Что автоматика знает и чего не знает
Разница видна не в рассуждении, а в списке атрибутов. Автоматические спаны:
| Спан | Атрибутов | Примеры |
|---|---|---|
POST /order (otelhttp, server) |
13 | http.request.method, http.response.status_code, url.path, client.address, user_agent.original |
HTTP GET (otelhttp, client) |
6 | http.request.method, url.full, server.address |
GET /inventory/{sku} (агент, Tomcat) |
14 | то же плюс http.route, thread.id, thread.name |
SELECT orders.inventory (агент, JDBC) |
11 | db.system, db.operation, db.sql.table, db.statement, db.user |
Ручной спан:
| Спан | Атрибутов | Какие |
|---|---|---|
create_order |
5 | order.sku, order.quantity, order.id, order.reserved, load.run |
Ни один автоматический атрибут не отвечает на вопрос «что за заказ и удалось ли его зарезервировать». Автоматика знает протоколы; предметную область знает только ваш код. Обратное тоже верно: расписывать руками http.request.method бессмысленно.
Ручная разметка в стенде выглядит так:
attrs := []attribute.KeyValue{
attribute.String("order.sku", req.SKU),
attribute.Int("order.quantity", req.Quantity),
}
if run, ok := ctx.Value(loadRunKey{}).(string); ok {
attrs = append(attrs, attribute.String("load.run", run))
}
ctx, span := s.tracer.Start(ctx, "create_order", trace.WithAttributes(attrs...))
defer span.End()Трассер и счётчик здесь берутся из глобальных провайдеров, а не передаются снаружи — и это осознанный выбор, а не лень:
// Трассер и счётчик берутся из ГЛОБАЛЬНЫХ провайдеров, а не передаются
// снаружи. Смысл именно в этом: при неинициализированном SDK глобальные
// провайдеры no-op, код ниже работает как обычно, а телеметрия никуда не
// уходит. Проверяется прогоном с OTEL_SDK_DISABLED=true.
tracer trace.Tracer
orders metric.Int64CounterДве находки в пользу автоматики
Первая: шаблон маршрута знают оба, но подают по-разному. У Java-агента http.route лежит отдельным атрибутом спана. У otelhttp в Go атрибута http.route в спане нет — но шаблон никуда не потерялся: он попадает в имя спана и в лейбл метрики. Проверено на параметризованном маршруте GET /order/{id}: пять запросов к /order/ord-1 … /order/ord-5 дали ровно одну серию с http_route="/order/{id}", а в спане при этом url.path = /order/ord-4 и никакого route в атрибутах.
Так что группировать метрики по маршруту в Go руками не нужно, и взрыва серий по идентификатору не происходит. Оговорка одна, и она важная: шаблон otelhttp берёт из http.ServeMux (r.Pattern, Go 1.22 и новее). Самописный роутер, который шаблона не отдаёт, положит в лейбл конкретный путь — вот там кардинальность взорвётся по-настоящему, и об этом отдельная статья серии.
Вторая: агент показывает то, о чём автор приложения не думает. В значениях db.statement обнаружился запрос, которого в коде нет вовсе:
SELECT sku, name, quantity, pg_sleep(?) FROM inventory WHERE sku = ?
SELECT sku, name, quantity FROM inventory WHERE sku = ?
INSERT INTO orders (order_id, sku, quantity, reserved) VALUES (?, ?, ?, ?) ON CONFLICT (order_id) DO NOTHING
SHOW TRANSACTION ISOLATION LEVELSHOW TRANSACTION ISOLATION LEVEL — это пул соединений Hikari, а не бизнес-логика.
И заодно уточнение к распространённому предупреждению «осторожно с PII в db.statement». Агент 2.30.0 по умолчанию сам обезличивает литералы: санитайзер разбирает готовый текст запроса и заменяет строковые и числовые литералы на ?. Ему всё равно, как этот текст собран, — значения, вклеенные в запрос конкатенацией, он заменит точно так же, как написанные в коде литералы; конкатенация опасна SQL-инъекцией, но обезличивание сама по себе не отключает. Предупреждение остаётся верным там, где санитайзер не срабатывает: он отключён (otel.instrumentation.common.db-statement-sanitizer.enabled=false), данные попали не в литерал (имена объектов, комментарии), или текст запроса кладёт в спан ручная инструментация либо библиотека, мимо которой агент не проходит.
Ресурсные атрибуты: кто это отправил
Ресурс — это ответ на вопрос «чей это сигнал». Без него в бэкендах каша: спан есть, а от кого он — неизвестно.
res, err := resource.New(ctx,
resource.WithFromEnv(),
resource.WithTelemetrySDK(),
resource.WithProcessRuntimeDescription(),
resource.WithAttributes(
semconv.ServiceName(serviceName),
semconv.ServiceVersion(serviceVersion),
),
)
if err != nil {
// Расхождение версий semconv между SDK и ресурсом даёт именно
// «частичную» ошибку, при которой ресурс всё же годен.
if !errors.Is(err, resource.ErrSchemaURLConflict) {
return nil, fmt.Errorf("ресурс: %w", err)
}
}Отдельного внимания стоит обработка ошибки. resource.New умеет возвращать ошибку, при которой ресурс всё равно годен к употреблению — например при расхождении версий семантических конвенций. Если трактовать любую ошибку как фатальную, приложение перестанет стартовать после безобидного обновления зависимости.
WithFromEnv подхватывает OTEL_SERVICE_NAME и OTEL_RESOURCE_ATTRIBUTES, поэтому в стенде идентичность задаётся снаружи, а не в коде:
OTEL_SERVICE_NAME: go-frontend
OTEL_RESOURCE_ATTRIBUTES: "service.version=1.0.0,deployment.environment=stand"Дальше эти атрибуты живут во всех трёх сигналах — и в этом есть подвох, который стоит знать заранее. В Loki часть их становится лейблами индекса, и по умолчанию в этот набор входит service.instance.id:
{"status":"success","data":["deployment_environment","service_instance_id","service_name"]}Выглядит безобидно — три лейбла. Но service.instance.id уникален для экземпляра: Java-агент генерирует новый UUID при каждом старте, в Kubernetes он свой у каждого пода. На стенде три перезапуска Java-сервиса дали 2, 3, 4, 5 потоков одному и тому же сервису, и это при дефолтной, «безопасной» настройке.
Поэтому в стенде набор индексных лейблов задан явно, а дефолтный отключён — service.instance.id остаётся доступным в structured metadata, но индекс не раздувает. Подробный опыт и настройка — в статье про логи и Loki; там же проверяется, что бывает, если в лейбл всё-таки уедет trace_id.
В метриках подвох другой. Collector экспонирует service.name как лейбл job, а Prometheus при скрейпе переименовывает его в exported_job, потому что свой job у него уже занят:
khorost_tech_orders_created_total{
exported_job="go-frontend", job="otelcol-apps", instance="otelcol:8889",
service_name="go-frontend", service_version="1.0.0",
deployment_environment="stand", reserved="false",
telemetry_sdk_language="go", telemetry_sdk_version="1.45.0"
} 13Мелочь, но запросы, написанные по привычке через job=, на таких данных вернут пустоту.
Экспорт в Collector: gRPC против HTTP
OTLP умеет ездить двумя транспортами: gRPC на порту 4317 и HTTP на 4318. Выбор выглядит как настройка одной переменной, но в двух языках он делается по-разному, и это первое, обо что спотыкаются.
У Java-агента протокол по умолчанию — http/protobuf. Агент прямо предупреждает, если ему дали порт gRPC:
WARN io.opentelemetry.exporter.otlp.internal.OtlpConfigUtil - OTLP exporter
endpoint port is likely incorrect for protocol version "http/protobuf".
The endpoint http://otelcol:4317 has port 4317. Typically, the
"http/protobuf" version of OTLP uses port 4318.Это, пожалуй, самая частая ошибка переноса примеров: конфигурация скопирована из Go-руководства, порт 4317, а агент по умолчанию говорит HTTP.
В Go SDK gRPC и HTTP — это разные модули, а не флаг. Переменная OTEL_EXPORTER_OTLP_PROTOCOL сама ничего не переключает: выбор делает код приложения, и оба модуля нужно собрать заранее.
var traceExp sdktrace.SpanExporter
if UseHTTP() {
traceExp, err = otlptracehttp.New(ctx)
} else {
traceExp, err = otlptracegrpc.New(ctx)
}
if err != nil {
return nil, fmt.Errorf("экспортёр трейсов: %w", err)
}Практическая разница между транспортами по замерам стенда оказалась скромной, и её видно в следующем разделе: по латентности неразличимо, по памяти Go-процесса gRPC дороже на 3–4 МиБ. То есть выбирают транспорт не из производительности, а из инфраструктуры — пройдёт ли gRPC через промежуточные прокси и балансировщики.
Сколько это стоит
Замер: 20 000 запросов, 8 параллельных отправителей, два повтора на каждый режим. Перед каждым прогоном стенд поднимается заново с чистыми томами и прогревается 600 запросами — без прогрева у JVM измеряется разогрев, а не работа. Латентность считается по успешным запросам без медленного SKU-0004, иначе pg_sleep(0.15) перетягивает перцентили на себя и скрывает разницу.
ПРОГОН p50 p90 p99 max время
baseline-1 4.7 12.1 27.0 80.4 52.776s
grpc-1 5.0 12.9 27.3 53.8 53.788s
httpproto-1 4.8 12.4 26.2 5365.4 59.07s
baseline-2 4.7 12.2 26.8 96.4 52.941s
grpc-2 4.9 12.6 28.5 78.1 53.472s
httpproto-2 4.8 12.3 25.9 51.8 52.89sРазница между базовой линией и инструментированным вариантом лежит на границе разброса: p50 4,7 против 4,9–5,0 мс, p99 26,8–27,0 против 25,9–28,5. По p99 инструментированные прогоны местами оказываются быстрее базовых.
Отсюда честный вывод, который приятнее было бы заменить бодрым процентом: на этом профиле нагрузки цена инструментирования по латентности не измеряется — она тонет в собственном шуме стенда. Утверждать «замедляет на N процентов» по таким данным нельзя.
Один выброс замалчивать тоже неправильно: httpproto-1 дал максимум 5365 мс при p99 26,2 мс. Один запрос из двадцати тысяч занял пять секунд; на перцентили это не повлияло, во втором проходе того же режима максимум 51,8 мс. Причину я не установил.
Заметнее всего различается процессор Java-сервиса:
| Режим | CPU java-backend, среднее по прогону (% одного ядра) |
|---|---|
| без агента | 49,6 % и 58,7 % |
| агент, Go по gRPC | 74,8 % и 69,4 % |
| агент, Go по HTTP | 60,4 % и 68,9 % |
В обоих повторах CPU Java-сервиса в инструментированных режимах выше базового — от 60,4 до 74,8 % против 49,6 и 58,7 %. Но это всё, что можно утверждать по таким данным. Повторов два, и режимы всегда шли в одном порядке. Главное — режим переключает сразу оба компонента: Java-агент включается вместе с Go SDK, и Java-сервис в этих прогонах получает ещё и входящий trace context, и соседа, который сам тратит процессор на экспорт. Вклад именно агента отдельно не выделен. Чтобы его выделить, нужны независимое переключение агента и SDK, больше повторов в перемешанном порядке и CPU-время на запрос, а не средняя загрузка за прогон. Что байткод-инструментирование стоит процессора, — ожидаемо; сколько именно на вашей нагрузке, этот замер не говорит. У Go разница не выделяется из шума: 42,3 и 47,9 % без SDK против 46,1 и 46,5 % с ним.
По памяти устойчивее выглядит Go:
| Режим | ОЗУ go-frontend, среднее |
|---|---|
OTEL_SDK_DISABLED=true |
18,8 и 18,9 МиБ |
| SDK, OTLP по gRPC | 30,6 и 29,0 МиБ |
| SDK, OTLP по HTTP | 26,1 и 26,0 МиБ |
То есть SDK стоит примерно 8–12 МиБ, а gRPC-вариант дороже HTTP на 3–4 МиБ — тянет свою реализацию транспорта.
А вот память Java по этим данным сравнивать нельзя, и это тоже результат. Базовая линия разошлась между повторами вдвое — 340,0 и 542,9 МиБ, — и этот разброс шире, чем разница с агентом (474–515 МиБ). Куча JVM растёт по своей логике; чтобы измерить вклад агента, нужен фиксированный -Xmx и больше повторов. В стенде этого не делалось, поэтому вывода о памяти Java здесь нет.
Отдельное число из проверки выполнимости стенда, полезное для прикидок: JVM с подключённым агентом на минимальном приложении (штатный jwebserver из JDK) занимала 223,6 МиБ против 28,7 МиБ без агента. Это не про Spring и не под нагрузкой, но порядок величины «сколько стоит сам агент по памяти» даёт.
Как этот замер дважды соврал
Два раза отчёт выглядел правдоподобно и был неверен. Оба раза выдавал один и тот же признак — среднее больше максимума.
Первый раз ресурсы снимались потоковым docker stats. Под нагрузкой он на этой машине отдавал -- / -- в 1468 строках из 1508 (97 %), а парсер считал прочерк нулём. Получалось «ОЗУ ср 0,4 МиБ при максимуме 17,5». Лечится сбором снимков --no-stream в цикле и явным подсчётом отброшенных точек.
Второй раз awk сравнивал загрузку процессора как строки: "104.32" лексикографически меньше "8.7", поэтому в отчёте появлялся максимум 8,7 % при среднем 47,9 %. Лечится приведением к числу.
Мораль простая и не новая: замер, который нельзя проверить на внутреннюю согласованность, проверять и не станут. Признак «среднее больше максимума» здесь сработал дважды — стоит закладывать такие проверки в сам скрипт.
Логи: контекст решает всё
Логи в стенде идут двумя маршрутами одновременно: JSON в stdout (его подхватит конвейер — Vector или Fluent Bit) и OTLP через мост otelslog прямо в Collector. Это не избыточность, а два разных пути доставки, которые в проде обычно сосуществуют.
// newLogger собирает логгер. Если SDK не инициализирован, остаётся только
// stdout — и это ровно то поведение, которое надо показать: приложение
// логирует, но в бэкенде логов нет.
func newLogger(lp *sdklog.LoggerProvider) *slog.Logger {
var stdout slog.Handler = traceContextHandler{
Handler: slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo}),
}
if lp == nil {
return slog.New(stdout)
}
bridge := otelslog.NewHandler("go-frontend", otelslog.WithLoggerProvider(lp))
return slog.New(fanoutHandler{handlers: []slog.Handler{stdout, bridge}})
}И тут обнаруживается разница между языками, которая стоила мне отдельного круга отладки. Java-агент прикрепляет trace_id к записям сам. В Go контекст нужно передавать явно, и slog.Info вместо slog.InfoContext тихо даёт записи с пустым trace_id: лог есть, связь с трейсом потеряна.
// ErrorContext, а не Error: без контекста запроса запись не получит trace_id,
// и потом по ошибочному трейсу не найти её лог.
s.Log.ErrorContext(s.logCtx(r.Context()), "запрос отклонён",
"status", code, "msg", msg, "err", errText(err), "path", r.URL.Path)Проверяется это не глазами, а критерием в обратную сторону: записей о заказе без trace_id должно быть ноль. Считать записи с trace_id бессмысленно — накопленное за прошлые прогоны само даст большое число.
== вердикт
ГОДЕН метрика заказов (дельта) 186 (ожидалось ровно 186)
ГОДЕН логи о заказах (дельта) 186 (ожидалось ровно 186)
ГОДЕН трейсы create_order 200 (ожидалось ровно 200)
ГОДЕН трейсы с ошибкой 14 (ожидалось ровно 14)
ГОДЕН логи без trace_id 0 (ожидалось ровно 0)Сравнение здесь точное, а не «не меньше»: получено больше ожидаемого — тоже отказ, потому что это либо дубли сигнала, либо посторонний трафик в стенд. Числа сходятся не случайно: 186 — успешные заказы, 200 — все запросы (спан create_order создаётся и на ошибочных, он стартует до обращения к складу), 14 — ровно ошибочные, то есть 8 отсутствий товара и 6 отказов бэкенда. Подробнее про модель Loki, лейблы и корреляцию в обе стороны — в третьей статье серии.
Итог
Что стоит забрать из этой статьи:
- API и SDK разделены не ради красоты. Приложение с инструментированным кодом и без SDK работает нормально и не отдаёт ничего: 120 запросов обслужены, трейсов ноль, метрика не выросла. Ошибок при этом нет — потому и ищут долго.
- Автоматика знает протоколы, предметную область знает только ваш код. Пять спанов на запрос, из них четыре получены без единой строки про телеметрию, но ни один автоматический атрибут не отвечает «что за заказ и зарезервирован ли он».
- Java-агент даёт больше, чем обёртки в Go:
thread.*, запросы пула соединений, обезличенныйdb.statement,http.routeотдельным атрибутом спана. Плата — процессор: в прогонах стенда 60–75 % против 50–59 % на том же профиле нагрузки, хотя вклад агента отдельно от включённого рядом Go SDK замер не выделяет. Оговорка: сам шаблон маршрута есть и в Go — в имени спана и в лейбле метрики. - Цена по латентности на обычном профиле не измеряется. Она тонет в разбросе, и это честнее любого процента. Измеримо другое: память Go-процесса растёт на 8–12 МиБ, CPU JVM — заметно.
- Три сигнала не равны по зрелости. Логи в Go SDK всё ещё
v0.21.0противv1.45.0у трейсов и метрик. - Транспорт OTLP выбирают не из производительности. У Java-агента по умолчанию
http/protobuf, в Go gRPC и HTTP — разные модули; разница в замерах — 3–4 МиБ памяти, всё остальное решает инфраструктура. - Логи связываются с трейсом только через контекст. В Go
slog.InfoвместоInfoContextмолча рвёт связь; критерий проверки — ноль записей безtrace_id, а не наличие записей с ним.
Дальше в серии: сквозной трейс через HTTP, PostgreSQL и NATS — что происходит на каждой границе и как трейс рвётся, если её не обработать.
Документация и первоисточники
- OpenTelemetry: Go SDK — инициализация провайдеров, экспортёры, семантические конвенции.
- OpenTelemetry: Java agent — подключение, настройка через переменные окружения, список поддерживаемых библиотек.
- OpenTelemetry: спецификация OTLP — транспорты, кодировки, порты.
- OpenTelemetry: semantic conventions — словарь атрибутов
http.*,db.*,messaging.*. - OpenTelemetry: environment variables —
OTEL_SDK_DISABLED,OTEL_RESOURCE_ATTRIBUTES,OTEL_EXPORTER_OTLP_*. - Стенд со всеми конфигами, скриптами и сырыми выводами замеров —
digital-cookbook/observability/practice-stack.
Комментарии