package obs import ( "context" "log/slog" "os" "strings" ) // NewLogger builds the process logger from the environment: LOG_LEVEL // (debug|info|warn|error, default info) and LOG_FORMAT (text|json, default // text). Writes to stderr with UTC timestamps. func NewLogger() *slog.Logger { opts := &slog.HandlerOptions{ Level: parseLogLevel(os.Getenv("LOG_LEVEL")), ReplaceAttr: func(_ []string, a slog.Attr) slog.Attr { if a.Key == slog.TimeKey && a.Value.Kind() == slog.KindTime { a.Value = slog.TimeValue(a.Value.Time().UTC()) } return a }, } var h slog.Handler if strings.EqualFold(strings.TrimSpace(os.Getenv("LOG_FORMAT")), "json") { h = slog.NewJSONHandler(os.Stderr, opts) } else { h = slog.NewTextHandler(os.Stderr, opts) } return slog.New(contextHandler{h}) } // contextHandler wraps a slog.Handler so a record logged with one of the // *Context methods automatically gets the call's trace_id AND the translation // axis (book/chapter/chunk/stage/role) attached — the userver-style trail, set // once at the top of a unit of work and carried through to the model call. // Records logged without a traced context simply carry none of these. type contextHandler struct{ slog.Handler } func (h contextHandler) Handle(ctx context.Context, r slog.Record) error { if ri, ok := ReqInfoFromContext(ctx); ok { if ri.TraceID != "" { r.AddAttrs(slog.String("trace_id", ri.TraceID)) } if ri.Book != "" { r.AddAttrs(slog.String("book", ri.Book), slog.Int("chapter", ri.Chapter), slog.Int("chunk", ri.Chunk)) } if ri.Stage != "" { r.AddAttrs(slog.String("stage", ri.Stage), slog.String("role", ri.Role)) } } return h.Handler.Handle(ctx, r) } // WithAttrs/WithGroup must re-wrap, or the embedded handler's versions would // return a bare handler and silently drop the trace_id injection for any child // logger (типовая ошибка обёрток, поймана ещё в vojo). func (h contextHandler) WithAttrs(attrs []slog.Attr) slog.Handler { return contextHandler{h.Handler.WithAttrs(attrs)} } func (h contextHandler) WithGroup(name string) slog.Handler { return contextHandler{h.Handler.WithGroup(name)} } // LogLLMExchange logs the raw request/response bodies of one model call at // DEBUG, but ONLY when the call's context opted in (ReqInfo.LogBodies) — // message content never enters the logs unless an operator explicitly enables // it AND runs at LOG_LEVEL=debug. Only the BODIES are logged — never the URL // or any header — so the API key cannot leak. Bodies are truncated. func LogLLMExchange(ctx context.Context, log *slog.Logger, provider string, reqBody []byte, status int, respBody []byte) { if log == nil { return } ri, ok := ReqInfoFromContext(ctx) if !ok || !ri.LogBodies { return } log.DebugContext(ctx, "llm exchange", "provider", provider, "status", status, "request", truncateForLog(reqBody, llmBodyLogMax), "response", truncateForLog(respBody, llmBodyLogMax), ) } // llmBodyLogMax caps each logged model body: keeps a typical prompt/answer // readable while staying bounded. A constant, not a knob — it only bounds log // volume on an opt-in debug path. const llmBodyLogMax = 4096 func truncateForLog(b []byte, maxBytes int) string { if len(b) > maxBytes { return string(b[:maxBytes]) + "…(truncated)" } return string(b) } func parseLogLevel(s string) slog.Level { switch strings.ToLower(strings.TrimSpace(s)) { case "debug": return slog.LevelDebug case "warn", "warning": return slog.LevelWarn case "error": return slog.LevelError default: return slog.LevelInfo } }