Структурные логи и корреляция запросов

1. Зачем вам вообще структурные логи в ChatGPT App

Представьте, что вам пишет продакт: “Пользователи жалуются, что при выборе подарка иногда показывается пустой список, а иногда checkout падает. Можно починить к завтрашнему демо?”. У вас есть:

• ChatGPT, который иногда вызывает ваш App, иногда — нет.
• Виджет в песочнице.
• MCP‑сервер, который дергает внешнюю базу товаров и ACP.
• Вебхуки от платёжки.

И только разрозненные текстовые логи вроде “something went wrong” где-то на MCP и “order failed” где-то на backend. При параллельных запросах это превращается в хаос: невозможно понять, какой лог относится к какому пользователю и к какому запросу.

Структурные JSON‑логи и единый trace_id как раз и нужны, чтобы:

• по одному идентификатору увидеть всю цепочку: от запроса ChatGPT до вебхука "order.created";
• фильтровать логи по сервису, инструменту, пользователю, сценарию;
• быстро ответить на вопросы “почему checkout упал” и “что делал агент перед тем, как начать галлюцинировать”.

То есть цель проста: сделать так, чтобы продакшн‑GiftGenius можно было дебажить и мониторить не хуже обычного микросервисного приложения.

2. Строковые vs структурные логи: почему console.log("ой") уже не работает

В обычной Next.js‑разработке многие ограничиваются строковыми логами: печатают человекочитаемую фразу и иногда пару значений. В одиночном сервисе это ещё терпимо. Но в стеке ChatGPT App такие логи очень быстро превращаются в кашу.

Текстовый лог — это просто одна строка в файле или консоли. Например:

console.error(`Error in suggestGifts for user ${userId}: ${error.message}`);

Когда таких сообщений сто тысяч, найти “все ошибки MCP в checkout с userId=… за вчера” уже непросто. А автоматически построить дашборд по ошибкам инструментов — почти нереально.

Структурный лог — это JSON‑объект, где помимо текста сообщения есть набор полей: уровень, время, сервис, идентификаторы, технический и бизнес‑контекст. Аналог предыдущего:

logger.error({
    message: "suggest_gifts failed",
    user_id: userId,
    trace_id,
    service: "mcp",
    tool_name: "suggest_gifts",
    error_message: error.message,
});

Каждое поле индексируется системой логирования (ELK, Loki, Better Stack, Datadog и т.п.), и дальше можно писать запросы вроде service="mcp" AND level="error" AND tool_name="suggest_gifts" или просто искать по trace_id="...".

Для наглядности — маленькая табличка.

В мире LLM‑приложений, где половина проблем — это не “500 ошибка”, а “модель вызвала не тот инструмент”, без структурных логов вы буквально слепы.

3. Анатомия JSON‑лога для ChatGPT App

Дальше договоримся о “минимальном стандарте” лог‑записи, который вы будете использовать во всех слоях GiftGenius. Он не идеален, но покрывает 80% задач.

Разобьём поля логов на несколько групп.

Технические поля

Технические поля нужны, чтобы инструментам наблюдаемости было понятно, откуда вообще пришла запись.

Можно описать их TypeScript‑типом:

type LogLevel = "debug" | "info" | "warn" | "error";

interface BaseLogFields {
    timestamp: string;    // ISO 8601 UTC
    level: LogLevel;      // "info", "error"...
    service: string;      // "app-widget", "mcp", "agent", "commerce", "webhook"
    env: "dev" | "staging" | "prod";
    message: string;      // Краткое описание события
}

timestamp лучше писать в ISO‑формате UTC ("2025-11-21T10:15:30.123Z"), тогда разные сервисы можно сортировать по времени без плясок с таймзонами. service и env помогают отделить, например, логи продакшн‑MCP от логов виджета в dev. Это особенно актуально, если вы позже захотите подружиться с OpenTelemetry и использовать общие конвенции service.name, service.version и т.п.

Поля корреляции

Это самое важное для этой лекции. Без них вы не сможете связать события между собой.

Добавим к нашему интерфейсу:

interface CorrelationFields {
    trace_id: string;        // Сквозной ID всего сценария
    span_id?: string;        // (опционально) ID конкретной операции
    parent_span_id?: string; // (опционально) Родительская операция
    request_id?: string;     // Локальный ID HTTP-запроса или tool-call
    agent_run_id?: string;   // ID запуска агента (если есть)
    tool_call_id?: string;   // ID вызова конкретного инструмента
    checkout_session_id?: string; // ID ACP/платёжной сессии
}

trace_id — главный герой. Он должен быть одним и тем же во всех логах, относящихся к сценарию “Пользователь попросил подобрать подарок, мы подобрали, создали заказ, получили webhook”. span_id и parent_span_id позволяют потом строить “дерево операций” в стиле distributed tracing, но для старта можно обойтись даже только trace_id и request_id.

Бизнес‑контекст

Технический лог без бизнес‑контекста превращается в “произошло что-то, где-то, когда-то”. Нам нужно понимать, какой пользователь и в каком шаге сценария был затронут.

Расширим интерфейс:

interface BusinessFields {
    user_id?: string;     // Анонимный ID, НЕ email
    tenant_id?: string;   // Организация/аккаунт, если B2B
    flow?: string;        // Например, "gift_recommendation" или "checkout"
    step?: string;        // Например, "collect_requirements" или "create_checkout"
}

Здесь принцип очень простой: идентификаторы могут быть внутренними (UUID из вашей БД), но не должны содержать PII (email, телефон, ФИО). Об этом ещё поговорим в разделе про безопасность.

Поля ошибок

Ошибки — отдельная песня. Типичный лог с ошибкой хочется разбить хотя бы на тип, код и текст:

interface ErrorFields {
    error_type?: "validation" | "upstream" | "timeout" | "system";
    error_code?: string;       // HTTP-статус, код БД или свой enum
    error_message?: string;    // Кратко и безопасно
    stack?: string;            // Стек, аккуратно с объёмом и PII
}

Важно, чтобы error_message не содержал чувствительных данных (вроде “failed for card 4111 1111 1111 1111”). Лучше "payment provider declined card" и какой-нибудь безопасный код.

Полный интерфейс лога

Соберём всё вместе:

export interface LogEvent
    extends BaseLogFields,
        CorrelationFields,
        BusinessFields,
        ErrorFields {
    // для дополнительных полей оставим запас
    [key: string]: unknown;
}

Такой интерфейс вы можете использовать и в MCP‑сервере, и в commerce‑бэкенде, и в агенте. Тогда все сервисы будут писать логи в одном формате, и корреляция превратится в приятную прогулку, а не в квест.

4. Простейший JSON‑логгер для GiftGenius (MCP‑сервер)

Начнём с чего‑то совсем минималистичного. Предположим, ваш MCP‑сервер — это Node.js/TypeScript‑приложение. Сделаем утилиту logger:

// mcp/logging.ts
import { LogEvent, LogLevel } from "./types";

function log(level: LogLevel, event: Omit<LogEvent, "level" | "timestamp">) {
    const enriched: LogEvent = {
        timestamp: new Date().toISOString(),
        level,
        env: process.env.NODE_ENV === "production" ? "prod" : "dev",
        ...event,
    };

    // Выводим JSON в stdout — дальше его соберёт лог-система
    console.log(JSON.stringify(enriched));
}

export const logger = {
    debug: (event: Omit<LogEvent, "level" | "timestamp">) =>
        log("debug", event),
    info: (event: Omit<LogEvent, "level" | "timestamp">) =>
        log("info", event),
    warn: (event: Omit<LogEvent, "level" | "timestamp">) =>
        log("warn", event),
    error: (event: Omit<LogEvent, "level" | "timestamp">) =>
        log("error", event),
};

Это не Pino и не Winston, но для курса нам важна именно идея: всё пишется как JSON с нормальными полями.

Теперь используем его в обработчике MCP‑инструмента suggest_gifts.

5. Логирование MCP‑инструмента: от входа до выхода

Предположим, у вас уже есть обработчик инструмента suggest_gifts, который принимает предпочтения пользователя и возвращает список SKU. Добавим туда логи.

Пусть мы заранее достали trace_id из HTTP‑заголовка x-trace-id (как его туда положить — разберём в следующем блоке про корреляцию).

// mcp/tools/suggestGifts.ts
import { logger } from "../logging";

export async function suggestGiftsTool(args: SuggestGiftsArgs, ctx: {
  traceId: string;
  userId?: string;
}) {
  logger.info({
    message: "suggest_gifts called",
    service: "mcp",
    trace_id: ctx.traceId,
    user_id: ctx.userId,
    tool_name: "suggest_gifts",
    flow: "gift_recommendation",
    step: "fetch_candidates",
  });

  try {
    const gifts = await fetchGiftsFromCatalog(args);

    logger.info({
      message: "suggest_gifts succeeded",
      service: "mcp",
      trace_id: ctx.traceId,
      user_id: ctx.userId,
      tool_name: "suggest_gifts",
      flow: "gift_recommendation",
      step: "rank_candidates",
      result_count: gifts.length,
    });

    return gifts;
  } catch (error: any) {
    logger.error({
      message: "suggest_gifts failed",
      service: "mcp",
      trace_id: ctx.traceId,
      user_id: ctx.userId,
      tool_name: "suggest_gifts",
      flow: "gift_recommendation",
      step: "fetch_candidates",
      error_type: "upstream",
      error_message: error.message,
    });
    throw error;
  }
}

Теперь по одному trace_id можно будет увидеть:

• что инструмент вообще был вызван;
• сколько кандидатов нашлось;
• на каком шаге он упал.

При этом нигде не фигурирует email или имя пользователя — только внутренний user_id.

6. Где рождается trace_id в ChatGPT App

Давайте же разберемся где должен рождаться trace_id. Важно понимать, что он не привязан к конкретному запросу. trace_id — это идентификатор именно бизнес-операции. Поэтому нужно разделять две типичные ситуации:

“Узкий” MCP‑инструмент

Это когда tool делает одну компактную операцию и сразу возвращает результат (без интерактивного UI):

• get_gifts_for_budget
• calculate_price
• save_lead и т.п.

В этом случае удобно считать: один вызов MCP‑инструмента = один бизнес-запрос = один trace. Сквозной trace_id рождается на стороне MCP‑gateway / MCP‑сервера при входе tool‑call (или берётся из уже существующего контекста трассировки, если вы используете OpenTelemetry). Дальше этот trace_id используется во всех внутренних вызовах (REST‑сервисы, базы, очереди) и попадает в логи как поле trace_id.

ChatGPT и Apps SDK сюда никак не вмешиваются: они просто отправляют JSON‑RPC tool‑call, а трассировка начинается у вас, в контролируемой зоне.

“Широкий” MCP‑инструмент (возвращает виджет)

Здесь tool не завершает бизнес‑операцию до конца, а запускает интерактивную сцену: возвращает виджет, который уже в песочнице делает десятки fetch()‑запросов (подгрузка списка подарков, фильтры, checkout и т.п.).

В таком сценарии сквозная трассировка устроена иначе:

• основные бизнес‑операции живут в HTTP‑запросах виджета к backend;
• поэтому каждый значимый fetch() из виджета к вашему backend получает свой trace_id, который рождается уже в backend / gateway (первый серверный hop для этого fetch).

Ни ChatGPT, ни сам виджет не являются “источником истины” для trace_id: они лишь могут передать в запрос какие‑то вспомогательные идентификаторы (session_id, widget_id, user_id), а вот создание и управление trace_id происходит на сервере.

“Узкий” MCP‑tool: один trace на tool‑call

Разберём, как выглядит поток для “узкого” инструмента без виджета:

sequenceDiagram
    participant ChatGPT as ChatGPT / Agent
    participant MCP as MCP Server
    participant GiftAPI as Gift API
    participant Pricing as Pricing API

    ChatGPT->>MCP: JSON-RPC tools.call get_gifts
    MCP->>MCP: start trace (trace_id = T-123)
    MCP->>GiftAPI: GET /gifts (x-trace-id = T-123)
    GiftAPI-->>MCP: 200 OK (trace_id = T-123)
    MCP->>Pricing: GET /price (x-trace-id = T-123)
    Pricing-->>MCP: 200 OK (trace_id = T-123)
    MCP-->>ChatGPT: tool result (опционально с trace_id)

Паттерн:

• при входе tool‑call в MCP вы создаёте trace (или берёте уже существующий из traceparent/x-trace-id);
• весь дальнейший путь этого tool‑call (вызовы сервисов, БД, кэшей) логируется с одним и тем же trace_id;
• в логах нет участия виджета, потому что никакого виджета нет.

Такой подход даёт:

• чёткий “снимок” одной операции: “MCP‑tool suggest_gifts → Gift API → Pricing API → ответ”;
• один trace_id на один вызов инструмента.

“Широкий” MCP‑tool: виджет и несколько trace’ов

Теперь сценарий GiftGenius, где MCP‑инструмент возвращает виджет:

1. ChatGPT вызывает MCP‑tool, например open_gift_widget.
2. MCP‑tool формирует описание виджета (layout, initial state) и возвращает его.
3. Виджет монтируется в песочнице и начинает жить своей жизнью:
   • GET /api/gifts?budget=50&page=1
   • GET /api/gifts?budget=50&filter=for_developers
   • POST /api/checkout
   • POST /api/save-lead
4. Каждый такой HTTP‑запрос приходит в ваш Next.js backend / gateway — и там вы создаёте новый trace:

fetch #1  -> trace_id = T-501  (загрузить первую страницу подарков)
fetch #2  -> trace_id = T-502  (применить фильтр “для разработчиков”)
fetch #3  -> trace_id = T-503  (создать checkout)
...

То есть:

• MCP‑tool “широкий”: его основная задача — открыть виджет, а не выполнить всю бизнес‑цепочку;
• реальная бизнес‑логика (список подарков, выбор топ‑подарка, checkout) живёт в бекенде, который обрабатывает fetch() виджета;
• группа fetch()‑запросов, объединенная одним бизнес‑сценарием, имеет свой уникальный trace_id, который вы генерируете на сервере при входе HTTP‑запроса.

Дополнительно вы можете прокидывать в каждый trace:

• session_id (ID сессии ChatGPT, если есть),
• widget_id,
• user_id,
• tool_run_id или любой другой контекст.

По trace_id вы смотрите конкретную операцию (“checkout #3”), по session_id / widget_id — всё, что происходило в рамках одного виджета/сеанса.

7. Корреляция запросов: как trace_id проходит через App, MCP, виджет и backend

Переходим к самой интересной части: как сделать так, чтобы нужные идентификаторы проходили через все слои: ChatGPT, MCP‑сервер, виджет, backend commerce и webhooks.

Поток запросов с trace_id (диаграмма “широкого” случая)

Небольшая схема, как это выглядит для GiftGenius:

sequenceDiagram
    participant ChatGPT as ChatGPT UI
    participant MCP as MCP Server
    participant Widget as GiftGenius Widget
    participant Backend as Next.js Backend
    participant ACP as Commerce API
    participant WH as Webhook Handler

    ChatGPT->>MCP: tools.call open_gift_widget
    MCP-->>ChatGPT: Widget description (layout, config)
    ChatGPT->>Widget: Рендер виджета в песочнице

    Widget->>Backend: GET /api/gifts (trace_id = T-501, рождается в Backend)
    Backend->>ACP: GET /gifts (x-trace-id = T-501)
    ACP-->>Backend: 200 OK (trace_id = T-501)
    Backend-->>Widget: JSON с подарками (trace_id = T-501 в логах)

    Widget->>Backend: POST /api/checkout (trace_id = T-503, рождается в Backend)
    Backend->>ACP: POST /checkout (x-trace-id = T-503)
    ACP-->>Backend: 200 OK (trace_id = T-503)
    ACP-->>WH: webhook order.created (x-trace-id = T-503)
    WH->>WH: Логирует событие (trace_id = T-503)

Обратите внимание:

• в этой схеме trace_id не генерируется виджетом;
• он появляется в точке входа HTTP‑запроса на ваш backend (Next.js route handler, API‑gateway и т.п.);
• дальше этот trace_id прокидывается:
  • в логи backend,
  • в заголовок x-trace-id при вызове ACP,
  • в вебхуки, если ACP его возвращает/прокидывает дальше.

6.5. Генерируем и прокидываем trace_id в backend для вызовов из виджета

Перепишем пример так, чтобы было явно видно: trace_id рождается в backend, а не в виджете.

// app/api/mcp/tools/call/route.ts (Next.js backend, proxy к MCP)
import { NextRequest, NextResponse } from "next/server";
import { v4 as uuidv4 } from "uuid";
import { logger } from "@/mcp/logging";

export async function POST(req: NextRequest) {
  // Если пришёл trace_id из внешнего мира (например, из gateway) — используем его.
  // Если нет — генерируем новый на входе в backend.
  const incomingTraceId = req.headers.get("x-trace-id");
  const traceId = incomingTraceId ?? uuidv4();
  const requestId = uuidv4();

  logger.info({
    message: "mcp.tools.call received from widget",
    service: "backend",
    trace_id: traceId,
    request_id: requestId,
  });

  const body = await req.json();

  const res = await fetch(process.env.MCP_SERVER_URL!, {
    method: "POST",
    headers: {
      "Content-Type": "application/json",
      "x-trace-id": traceId,
    },
    body: JSON.stringify(body),
  });

  const json = await res.json();

  logger.info({
    message: "mcp.tools.call completed",
    service: "backend",
    trace_id: traceId,
    request_id: requestId,
  });

  return NextResponse.json(json);
}

А на стороне MCP‑сервера мы просто читаем этот заголовок и используем trace_id в своих логах (как в примерах из раздела 5).

Виджет при этом может даже не знать про существование trace_id — ему достаточно вызвать /api/mcp/tools/call. Но если вам удобно отображать или логировать действия UI с привязкой к трассировке, можно возвращать trace_id в ответе и писать, например, service: "app-widget" в собственные JSON‑логи (клиентские или через SaaS‑аналитику).

Пример клиентского вызова MCP из виджета

// app/lib/mcpClient.ts (виджет)
export async function callMcpTool(toolName: string, args: unknown) {
  const res = await fetch("/api/mcp/tools/call", {
    method: "POST",
    headers: {
      "Content-Type": "application/json",
      // trace_id НЕ генерируем здесь — он родится в backend
    },
    body: JSON.stringify({ toolName, args }),
  });

  // Если backend вернёт trace_id в теле, можно его сохранить:
  const data = await res.json();
  return data;
}

Если хотите, можете расширить backend‑обработчик, чтобы он добавлял trace_id в JSON‑ответ, и тогда виджет сможет:

• логировать события вида "service": "app-widget", "trace_id": "...",
• отображать trace‑ссылки для разработчиков.

Но принцип остаётся прежним: источник trace_id — сервер, а не виджет.

Прокидываем trace_id дальше в ACP/commerce

Теперь внутри MCP‑инструмента create_checkout_session мы вызываем ваш commerce API и всё ещё несём trace_id в заголовках:

// mcp/tools/createCheckout.ts
import { logger } from "../logging";

export async function createCheckoutTool(
  args: CreateCheckoutArgs,
  ctx: { traceId: string; userId?: string }
) {
  logger.info({
    message: "create_checkout called",
    service: "mcp",
    trace_id: ctx.traceId,
    user_id: ctx.userId,
    tool_name: "create_checkout_session",
    flow: "checkout",
    step: "create_session",
  });

  const res = await fetch(process.env.COMMERCE_URL + "/checkout", {
    method: "POST",
    headers: {
      "Content-Type": "application/json",
      "x-trace-id": ctx.traceId,
    },
    body: JSON.stringify({
      userId: ctx.userId,
      ...args,
    }),
  });

  if (!res.ok) {
    logger.error({
      message: "checkout API failed",
      service: "mcp",
      trace_id: ctx.traceId,
      user_id: ctx.userId,
      flow: "checkout",
      step: "create_session",
      error_type: "upstream",
      error_code: String(res.status),
    });
    throw new Error("Checkout API failed");
  }

  const data = await res.json();

  logger.info({
    message: "checkout session created",
    service: "mcp",
    trace_id: ctx.traceId,
    user_id: ctx.userId,
    flow: "checkout",
    step: "create_session",
    checkout_session_id: data.sessionId,
  });

  return data;
}

Commerce‑бэкенд, в свою очередь, тоже читает x-trace-id и пишет его в свои JSON‑логи. Тогда по одному trace_id вы увидите:

• входящий HTTP‑запрос от виджета в backend (где trace родился);
• проксирование в MCP (если оно есть);
• внутренний вызов create_checkout_session;
• запрос в commerce API;
• ответ commerce‑бэкенда;
• и, если он тоже прокидывает заголовок, webhook order.created.

8. Уровни логов: DEBUG, INFO, WARN, ERROR в контексте LLM‑приложения

Уровни логов помогают не утонуть в информации. В ChatGPT App их удобно трактовать так:

• DEBUG — детальная техническая информация, полезная в dev/staging. Например, сокращённые промпты, промежуточные состояния агента, “сырые” ответы внешних API (без PII). В продакшене с ним нужно быть очень осторожным.
• INFO — нормальные бизнес‑события: “suggest_gifts succeeded, 10 кандидатов”, “checkout session created”, “webhook order.created processed”. Эти логи можно оставлять включёнными в проде.
• WARN — что-то пошло нестандартно, но система продолжила работать. Например: “fallback to cached catalog because upstream timeout”, “model returned invalid tool args, retry with different schema”.
• ERROR — явный провал: сценарий не завершился как надо. Например: “checkout API failed”, “failed to persist order”, “tool crashed with unhandled exception”.

Для удобства можно добавить простой хелпер, чтобы не писать руками строки:

type LogLevel = "debug" | "info" | "warn" | "error";

function isProd() {
  return process.env.NODE_ENV === "production";
}

export function shouldLogLevel(level: LogLevel): boolean {
  if (isProd()) {
    return level === "info" || level === "warn" || level === "error";
  }
  return true; // в dev включаем всё
}

И вызывать logger.debug только когда shouldLogLevel("debug") возвращает true.

Особенно опасно в продакшене писать DEBUG‑логи с полным промптом и ответом модели: там легко могут оказаться пароли, ключи, любая PII, которую пользователь по ошибке вставил в чат.

9. Безопасность логов: PII‑scrub и секреты

С логами легко переусердствовать. Если писать “всё подряд”, вы:

• нарушите законы о защите данных;
• упростите жизнь злоумышленнику (секреты и токены можно просто вытащить из логов);
• сами будете бояться, к кому дать доступ к лог‑системе.

Поэтому действует простой принцип: в логах достаточно информации, чтобы понять, что случилось, но недостаточно, чтобы украсть данные.

Хорошие практики:

1. Логируем user_id, а не email или телефон. Если вам всё же нужен email в логах для отладки, логируйте его хеш или маскируйте ("a***@gmail.com").
2. Никогда не пишем в логах полные токены ("sk-..."), refresh‑токены, client_secret, пароли. Если очень нужно — только первые/последние 4 символа и тип (“sk-***1234”).
3. Аккуратно с tool_input и tool_output. В них может быть всё, что написал пользователь. В продакшене либо не логируйте их целиком, либо:
   • логируйте только типизированные поля, уже прошедшие валидацию;
   • обрезайте до разумного размера и применяйте scrub — маскирование по регуляркам (email, номера карт и т.п.).

Простейший пример санитайзера (очень упрощённо):

export function sanitize(text: string): string {
  return text
    .replace(/sk-[a-zA-Z0-9]{20,}/g, "sk-***redacted***")
    .replace(/\b\d{16}\b/g, "****-****-****-****"); // карты
}

И при логировании пользовательского ввода:

logger.debug({
  message: "raw_user_message",
  service: "app-widget",
  trace_id,
  user_id,
  raw: sanitize(userMessage),
});

Этот код далёк от промышленного уровня, но хорошо показывает идею: сначала чистим, потом логируем.

10. Практика: событие gift_recommended для GiftGenius

Теперь сделаем то самое упражнение: спроектируем лог‑событие gift_recommended, которое записывается, когда GiftGenius окончательно выбирает “топ‑подарок” для пользователя.

Событие должно позволить ответить на вопросы:

• какой пользователь (внутренний ID);
• какой подарок (SKU);
• по какому сценарию и на каком шаге;
• какой trace_id, чтобы связать с остальными логами.

И одновременно не должно содержать PII и секретов.

Пример:

{
  "timestamp": "2025-11-21T10:22:33.456Z",
  "level": "info",
  "service": "agent",
  "env": "prod",
  "message": "gift_recommended",
  "trace_id": "a3b9e8c2-1f47-4ec5-9bdf-9d4e0c123abc",
  "agent_run_id": "run_7f1d2c",
  "user_id": "u_123456",
  "flow": "gift_recommendation",
  "step": "final_choice",
  "recommended_sku": "SKU-SPACE-MUG-001",
  "price_cents": 2499,
  "currency": "USD",
  "reason_summary": "recipient_likes_space_and_practical_gadgets"
}

Что здесь важно:

• Мы логируем user_id, но не email и не имя;
• SKU и цена — это нормальные бизнес‑данные, которые не считаются PII;
• reason_summary — краткий технический тег, а не полная фраза пользователя;
• есть trace_id и agent_run_id, чтобы можно было посмотреть, какие инструменты вызывал агент по пути к этому выбору.

А вот что логировать точно не нужно:

• текст ответа модели целиком с “человеческим” объяснением;
• промпт пользователя (“хочу подарок для коллеги Маши, у неё телефон такой‑то, адрес такой‑то”);
• любые платёжные данные.

11. Примеры логов: успешный tool‑call и ошибка ACP

Для закрепления — два небольших JSON‑примера.

Успешный tools.call на MCP

{
  "timestamp": "2025-11-21T10:20:00.000Z",
  "level": "info",
  "service": "mcp",
  "env": "prod",
  "message": "tools.call completed",
  "trace_id": "a3b9e8c2-1f47-4ec5-9bdf-9d4e0c123abc",
  "request_id": "req_01JCQ5CZ0YQ6TM7E5W8H3N3F2Y",
  "tool_name": "suggest_gifts",
  "user_id": "u_123456",
  "flow": "gift_recommendation",
  "step": "rank_candidates",
  "result_count": 12,
  "latency_ms": 430
}

Из одного такого лога уже видно:

• какой инструмент;
• для какого пользователя;
• по какому сценарию;
• сколько заняло по времени и сколько кандидатов вернули.

По trace_id вы легко найдёте логи UI и агента, относящиеся к тому же запросу.

Ошибка ACP/checkout

{
  "timestamp": "2025-11-21T10:21:05.789Z",
  "level": "error",
  "service": "commerce",
  "env": "prod",
  "message": "checkout failed",
  "trace_id": "a3b9e8c2-1f47-4ec5-9bdf-9d4e0c123abc",
  "checkout_session_id": "cs_test_9YpQvJH8",
  "user_id": "u_123456",
  "flow": "checkout",
  "step": "charge_customer",
  "error_type": "upstream",
  "error_code": "PAYMENT_DECLINED",
  "error_message": "payment provider declined card",
  "provider": "stripe",
  "amount_cents": 2499,
  "currency": "USD"
}

Снова, никакого номера карты, только код ошибки и безопасное сообщение. И опять же, тот же trace_id, поэтому вы можете связать этот лог с gift_recommended и понять, на каком этапе цепочка сломалась.

12. Как не превратить логи в мусор

Очень соблазнительно: “раз уж мы умеем логировать всё красиво, давайте логировать абсолютно всё”. Так вы быстро получите гигабайты JSON‑шума, в котором полезные события теряются.

Несколько практических советов:

• Дублирующие логи “я вошёл в функцию X” без дополнительной информации мало полезны. Лучше логировать значимые события: начало/конец сценария, вызов внешнего API, переход шага workflow, ошибки.
• Для частых операций (например, запросы к каталогу товаров) можно включить sampling: логировать 1 из N запросов целиком, а остальные — только при ошибках.
• В продакшене держите DEBUG выключенным (или очень сильно выборочным). Если логированию промптов/ответов быть — то ограниченно и с scrub.

Про метрики и SLO мы отдельно поговорим в следующей лекции, но уже сейчас важно понимать: логи — это не только “для отладки”, это фундамент наблюдаемости всего ChatGPT‑стека.

Помните продакта из начала лекции с «пустым списком» и падающим checkout? С описанной схемой логов вы бы за пару минут нашли все запросы с нужным trace_id, посмотрели suggest_gifts (сколько кандидатов вернул инструмент, на каком шаге он упал) и логи "checkout failed" c error_code от платёжки. Это уже не расследование “по логовой каше”, а понятный сценарий “от запроса до webhook’а”.

В итоге хороший стек логирования для ChatGPT App — это не «мы что-то пишем в stdout», а:

• корректные места рождения trace_id (в MCP‑gateway/сервере для “узких” tools и в backend‑входе для fetch() виджета в “широких” сценариях);
• единый trace_id сквозь App → MCP → commerce → webhooks для каждого осмысленного бизнес‑вызова;
• общая схема JSON‑логов (service, env, user_id, flow, step, tool_name и т.п.);
• аккуратное обращение с PII и секретами (scrub, маскирование, ограниченный DEBUG в продакшене);
• осмысленные уровни логов и отсутствие шума.

С такой базой все остальные инструменты наблюдаемости (метрики, SLO, алерты) становятся гораздо полезнее и помогают не просто “собирать логи”, а реально управлять качеством и стабильностью вашего ChatGPT App.

13. Типичные ошибки при работе со структурными логами и корреляцией

Ошибка №1: отсутствие единого trace_id через все сервисы.
Классический случай: MCP‑gateway генерирует один ID, commerce‑бэкенд — второй, вебхуки вообще ничего не знают про корреляцию, а в логах виджета trace_id не фигурирует. В результате корреляция превращается в ручной поиск “ну тут похоже время совпадает”. Правильный подход — генерировать trace_id в контролируемых точках входа (MCP‑сервер для “узких” tools, backend/gateway — для fetch() из виджета) и протаскивать его через все границы: HTTP‑заголовки, JSON‑поля, контекст агента.

Ошибка №2: попытка генерировать trace_id в виджете и считать его “истиной”.
Иногда кажется логичным: “давайте сразу в React‑виджете сделаем crypto.randomUUID() и будем вешать его в заголовки”. Проблема в том, что тогда trace_id живёт на клиенте и может не совпадать с реальной серверной трассировкой (OpenTelemetry, gateway, другие сервисы). Гораздо надёжнее, чтобы trace_id появлялся там, где вы контролируете весь серверный путь: в Next.js backend, API‑gateway или MCP‑сервере. Виджет при желании может этот ID только читать и логировать.

Ошибка №3: логирование PII и секретов “для удобства отладки”.
В начале разработки “очень удобно” просто записать в лог всё тело промпта, токены, номера карт и email. Через пару месяцев это превращается в мину замедленного действия: доступ к логам становится токсичным, аудит безопасности задаёт неприятные вопросы, а вы боитесь даже показывать скриншот ошибки. С самого начала внедряйте scrub и не логируйте то, что завтра придётся судорожно вычищать.

Ошибка №4: строковые логи без структуры в одном из слоёв.
Иногда команда делает крутые JSON‑логи в MCP и commerce, но в виджете оставляет console.log("step 1", data). В результате начало и конец цепочки остаются разорванными.

Ошибка №5: злоупотребление уровнем ERROR.
Если любое незначительное отклонение (типа “модель вернула 0 кандидатов, показываем fallback”) логируется как ERROR, продакшн‑алерты будут гореть постоянно. Команда быстро перестаёт реагировать на алерты вообще. Старайтесь честно разделять: “WARN — странно, но мы вырулили; ERROR — пользовательский сценарий реально сломался”.

Ошибка №6: несогласованные схемы логов между сервисами.
Когда в одном сервисе поле называется traceId, в другом correlation_id, а в третьем requestId, никакая лог‑система не спасёт. Важно договориться о единой схеме (как мы сделали с LogEvent) и придерживаться её во всех компонентах: App‑виджет, MCP‑сервер, агенты, ACP, вебхуки. Тогда построение сквозных дашбордов и расследование инцидентов станет задачей минут, а не дней.

Ошибка №7: попытка “оптимизировать” размер логов за счёт выкидывания ключевых полей.
Иногда в погоне за экономией места кто‑то решает: “давайте уберём user_id или flow, всё равно это мелочь”. Потом внезапно нужно ответить на вопрос “у каких пользователей чаще всего падает checkout?” — и оказывается, что информации нет. Если выбирать, что выкидывать, то длинные текстовые payload’ы (тела запросов/ответов) и отладочные поля, а не идентификаторы и ключевые контекстные атрибуты.