uvicorn_logging.go

package main

import (
	"encoding/json"
	"fmt"
	"os"
	"path/filepath"
)

// Health probes are not traffic. A kubelet asks /healthz and /readyz every
// few seconds for the life of a pod, and uvicorn's access log writes one line
// per answer: on a cell that was 180 lines per pod every ten minutes, all of
// them "200 OK", shipped to the telemetry store as if they were requests. The
// trace of a real request already carries what an access line says; a probe
// hit says nothing anyone reads.
//
// The service is not asked to know this. The agent hands uvicorn a logging
// configuration — uvicorn's own default, with one filter on the access
// handler — and the filter's module, in both places a service runs: written
// beside the project for a native run (`uv run uvicorn` puts the working
// directory on sys.path) and copied into the image by the builder. A service
// that configures its own logging is untouched: --log-config only shapes
// uvicorn's loggers.

// uvicornLogConfigFile and uvicornLoggingModule are the two files, named so a
// service's .gitignore can name them: they are the agent's, regenerated on
// every start, never the service's source.
const (
	uvicornLogConfigFile = "uvicorn-log-config.json"
	uvicornLoggingModule = "codefly_uvicorn_logging.py"
)

// probePaths is the set a kubelet (and a mesh, and a load balancer) probes.
const probePaths = `^/(healthz|readyz|livez|health|ready|live|ping)$`

// uvicornLoggingModuleSource is the filter: uvicorn's access record carries
// the request as its args (client address, method, path, HTTP version, status
// code), and a probe path is dropped before the handler formats it.
const uvicornLoggingModuleSource = `"""Codefly's uvicorn logging filter. Generated by the python-fastapi agent;
regenerated on every start, so edits here do not survive. Health probes are
not traffic: an access-log line for /healthz or /readyz is dropped before it is
formatted, and every other line is written exactly as uvicorn writes it."""
import logging
import re

PROBE_PATHS = re.compile(r"` + probePaths + `")


class ProbeFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        args = record.args
        if isinstance(args, tuple) and len(args) >= 3 and isinstance(args[2], str):
            path = args[2].split("?", 1)[0]
            if PROBE_PATHS.match(path):
                return False
        return True
`

// uvicornLogConfig is uvicorn's default logging configuration (its
// config.LOGGING_CONFIG) with the probe filter on the access handler. Restated
// rather than merged because --log-config replaces the default whole.
func uvicornLogConfig() map[string]any {
	return map[string]any{
		"version":                  1,
		"disable_existing_loggers": false,
		"filters": map[string]any{
			"probes": map[string]any{"()": "codefly_uvicorn_logging.ProbeFilter"},
		},
		"formatters": map[string]any{
			"default": map[string]any{
				"()":         "uvicorn.logging.DefaultFormatter",
				"fmt":        "%(levelprefix)s %(message)s",
				"use_colors": nil,
			},
			"access": map[string]any{
				"()":  "uvicorn.logging.AccessFormatter",
				"fmt": `%(levelprefix)s %(client_addr)s - "%(request_line)s" %(status_code)s`,
			},
		},
		"handlers": map[string]any{
			"default": map[string]any{"formatter": "default", "class": "logging.StreamHandler", "stream": "ext://sys.stderr"},
			"access":  map[string]any{"formatter": "access", "class": "logging.StreamHandler", "stream": "ext://sys.stdout", "filters": []string{"probes"}},
		},
		"loggers": map[string]any{
			"uvicorn":        map[string]any{"handlers": []string{"default"}, "level": "INFO", "propagate": false},
			"uvicorn.error":  map[string]any{"level": "INFO"},
			"uvicorn.access": map[string]any{"handlers": []string{"access"}, "level": "INFO", "propagate": false},
		},
	}
}

// writeUvicornLogging writes the configuration and the filter module into dir,
// the directory uvicorn runs from. Both are rewritten whole on every call.
func writeUvicornLogging(dir string) error {
	config, err := json.MarshalIndent(uvicornLogConfig(), "", "  ")
	if err != nil {
		return fmt.Errorf("render uvicorn logging configuration: %w", err)
	}
	for name, content := range map[string][]byte{
		uvicornLogConfigFile: append(config, '\n'),
		uvicornLoggingModule: []byte(uvicornLoggingModuleSource),
	} {
		if err := os.WriteFile(filepath.Join(dir, name), content, 0o644); err != nil {
			return fmt.Errorf("write %s: %w", name, err)
		}
	}
	return nil
}