Add observability module: Spring AI built-in meters and spans, cost per endpoint from token usage, Prometheus and Grafana dashboard

Co-Authored-By: Claude Sonnet 5.5 <[email protected]>
Claude-Session: https://claude.ai/code/session_01JXVi2GMQ7bR5EmbUFdDj7N

observability/src/main/java/com/ankurm/observability/AiController.java

@@ -0,0 +1,47 @@
+package com.ankurm.observability;
+
+import org.springframework.ai.chat.client.ChatClient;
+import org.springframework.web.bind.annotation.GetMapping;
+import org.springframework.web.bind.annotation.RequestParam;
+import org.springframework.web.bind.annotation.RestController;
+import reactor.core.publisher.Flux;
+
+/**
+ * Four endpoints, each tagging its ChatClient call with an {@code endpoint} value in the request
+ * context. {@link EndpointTagConvention} turns that into a metric tag, which is what lets the
+ * dashboard show cost per endpoint.
+ */
+@RestController
+public class AiController {
+
+    private final ChatClient chat;
+
+    private final WeatherTools tools;
+
+    public AiController(ChatClient.Builder builder, WeatherTools tools) {
+        this.chat = builder.build();
+        this.tools = tools;
+    }
+
+    @GetMapping("/ask")
+    public String ask(@RequestParam String q) {
+        return chat.prompt().user(q).advisors(a -> a.param(EndpointTagConvention.KEY, "ask")).call().content();
+    }
+
+    @GetMapping("/summarize")
+    public String summarize(@RequestParam String text) {
+        return chat.prompt().system("Summarize the user's text in one sentence.").user(text)
+                .advisors(a -> a.param(EndpointTagConvention.KEY, "summarize")).call().content();
+    }
+
+    @GetMapping("/weather")
+    public String weather(@RequestParam String city) {
+        return chat.prompt().user("What is the weather in " + city + "?").tools(tools)
+                .advisors(a -> a.param(EndpointTagConvention.KEY, "weather")).call().content();
+    }
+
+    @GetMapping("/stream")
+    public Flux<String> stream(@RequestParam String q) {
+        return chat.prompt().user(q).advisors(a -> a.param(EndpointTagConvention.KEY, "stream")).stream().content();
+    }
+}

observability/src/main/java/com/ankurm/observability/EndpointTagConvention.java

@@ -0,0 +1,22 @@
+package com.ankurm.observability;
+
+import io.micrometer.common.KeyValue;
+import io.micrometer.common.KeyValues;
+import org.springframework.ai.chat.client.observation.ChatClientObservationContext;
+import org.springframework.ai.chat.client.observation.DefaultChatClientObservationConvention;
+
+/**
+ * Adds an {@code app.endpoint} tag to the ChatClient observation, taken from the request context.
+ * It is a LOW-cardinality key, so it becomes a metric tag: keep the set of values small and fixed
+ * (an endpoint name), never a user id or a prompt.
+ */
+public class EndpointTagConvention extends DefaultChatClientObservationConvention {
+
+    public static final String KEY = "endpoint";
+
+    @Override
+    public KeyValues getLowCardinalityKeyValues(ChatClientObservationContext context) {
+        Object endpoint = context.getRequest().context().get(KEY);
+        return super.getLowCardinalityKeyValues(context).and(KeyValue.of("app.endpoint", endpoint == null ? "none" : endpoint.toString()));
+    }
+}

observability/src/main/java/com/ankurm/observability/ObservabilityApplication.java

@@ -0,0 +1,14 @@
+package com.ankurm.observability;
+
+import org.springframework.boot.SpringApplication;
+import org.springframework.boot.autoconfigure.SpringBootApplication;
+import org.springframework.boot.context.properties.ConfigurationPropertiesScan;
+
+@SpringBootApplication
+@ConfigurationPropertiesScan
+public class ObservabilityApplication {
+
+    public static void main(String[] args) {
+        SpringApplication.run(ObservabilityApplication.class, args);
+    }
+}

observability/src/main/java/com/ankurm/observability/ObservabilityConfig.java

@@ -0,0 +1,20 @@
+package com.ankurm.observability;
+
+import io.micrometer.core.instrument.MeterRegistry;
+import org.springframework.ai.chat.client.observation.ChatClientObservationConvention;
+import org.springframework.context.annotation.Bean;
+import org.springframework.context.annotation.Configuration;
+
+@Configuration
+public class ObservabilityConfig {
+
+    @Bean
+    ChatClientObservationConvention endpointTagConvention() {
+        return new EndpointTagConvention();
+    }
+
+    @Bean
+    UsageCostObservationHandler usageCostObservationHandler(MeterRegistry registry, Pricing pricing) {
+        return new UsageCostObservationHandler(registry, pricing);
+    }
+}

observability/src/main/java/com/ankurm/observability/Pricing.java

@@ -0,0 +1,25 @@
+package com.ankurm.observability;
+
+import java.util.Map;
+
+import org.springframework.boot.context.properties.ConfigurationProperties;
+
+/** USD per one million tokens, by model name prefix. Prices are configuration, not code: they change. */
+@ConfigurationProperties(prefix = "ai.pricing")
+public record Pricing(Map<String, Price> models) {
+
+    public record Price(double inputPerMillion, double outputPerMillion) {
+    }
+
+    /** Longest configured prefix of the model name wins, so "gpt-4o-mini-2024-07-18" matches "gpt-4o-mini" and not "gpt-4o". */
+    public Price forModel(String model) {
+        if (model == null || models == null) {
+            return null;
+        }
+        return models.entrySet().stream()
+                .filter(e -> model.startsWith(e.getKey()))
+                .max(java.util.Comparator.comparingInt(e -> e.getKey().length()))
+                .map(Map.Entry::getValue)
+                .orElse(null);
+    }
+}

observability/src/main/java/com/ankurm/observability/UsageCostObservationHandler.java

@@ -0,0 +1,57 @@
+package com.ankurm.observability;
+
+import io.micrometer.core.instrument.Counter;
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.observation.Observation;
+import io.micrometer.observation.ObservationHandler;
+import org.springframework.ai.chat.client.ChatClientResponse;
+import org.springframework.ai.chat.client.observation.ChatClientObservationContext;
+import org.springframework.ai.chat.metadata.Usage;
+import org.springframework.ai.chat.model.ChatResponse;
+
+/**
+ * When a ChatClient call finishes, reads the token usage the provider reported and records two
+ * counters tagged by endpoint and model: {@code app.ai.tokens} and {@code app.ai.cost.usd}. Cost is
+ * tokens times the configured price. If the provider reported no usage, or the model has no price,
+ * it counts the call under {@code app.ai.unpriced} instead of silently recording zero. A response
+ * with no usage block arrives as a usage of 0 tokens, not as null, and a real call always has at
+ * least one prompt token, so zero is treated as "no usage".
+ */
+public class UsageCostObservationHandler implements ObservationHandler<ChatClientObservationContext> {
+
+    private final MeterRegistry registry;
+
+    private final Pricing pricing;
+
+    public UsageCostObservationHandler(MeterRegistry registry, Pricing pricing) {
+        this.registry = registry;
+        this.pricing = pricing;
+    }
+
+    @Override
+    public boolean supportsContext(Observation.Context context) {
+        return context instanceof ChatClientObservationContext;
+    }
+
+    @Override
+    public void onStop(ChatClientObservationContext context) {
+        String endpoint = String.valueOf(context.getRequest().context().getOrDefault(EndpointTagConvention.KEY, "none"));
+        ChatClientResponse response = context.getResponse();
+        ChatResponse chat = response == null ? null : response.chatResponse();
+        Usage usage = chat == null || chat.getMetadata() == null ? null : chat.getMetadata().getUsage();
+        String model = chat == null || chat.getMetadata() == null ? null : chat.getMetadata().getModel();
+        Pricing.Price price = pricing.forModel(model);
+        boolean noUsage = usage == null || usage.getPromptTokens() == null || usage.getPromptTokens() == 0;
+        if (noUsage || price == null) {
+            Counter.builder("app.ai.unpriced").tag("endpoint", endpoint).tag("reason", noUsage ? "no-usage" : "no-price")
+                    .register(registry).increment();
+            return;
+        }
+        long in = usage.getPromptTokens();
+        long out = usage.getCompletionTokens() == null ? 0 : usage.getCompletionTokens();
+        Counter.builder("app.ai.tokens").tag("endpoint", endpoint).tag("model", model).tag("type", "input").register(registry).increment(in);
+        Counter.builder("app.ai.tokens").tag("endpoint", endpoint).tag("model", model).tag("type", "output").register(registry).increment(out);
+        Counter.builder("app.ai.cost.usd").tag("endpoint", endpoint).tag("model", model).baseUnit("usd").register(registry)
+                .increment(in * price.inputPerMillion() / 1_000_000d + out * price.outputPerMillion() / 1_000_000d);
+    }
+}

observability/src/main/java/com/ankurm/observability/WeatherTools.java

@@ -0,0 +1,14 @@
+package com.ankurm.observability;
+
+import org.springframework.ai.tool.annotation.Tool;
+import org.springframework.stereotype.Component;
+
+/** A tool the model can call, so the tool-calling observation has something to measure. */
+@Component
+public class WeatherTools {
+
+    @Tool(description = "Current temperature in Celsius for a city")
+    public String getWeather(String city) {
+        return city + ": 24 C, clear";
+    }
+}

observability/src/main/java/com/ankurm/observability/fake/FakeOpenAiServer.java

@@ -0,0 +1,158 @@
+package com.ankurm.observability.fake;
+
+import java.io.IOException;
+import java.io.OutputStream;
+import java.net.InetSocketAddress;
+import java.nio.charset.StandardCharsets;
+import java.util.ArrayList;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+
+import com.sun.net.httpserver.HttpExchange;
+import com.sun.net.httpserver.HttpServer;
+import tools.jackson.databind.JsonNode;
+import tools.jackson.databind.json.JsonMapper;
+
+/**
+ * A tiny stand-in for the OpenAI chat completions endpoint, so the REAL {@code OpenAiChatModel}
+ * (and with it Spring AI's real observation code) runs without an API key. It speaks just enough of
+ * the protocol: a plain answer, a tool call followed by a final answer, a streamed answer, and an
+ * HTTP 500. Token counts are a deterministic function of text length (about four characters per
+ * token) -- they are NOT real tokenizer output, so only their consistency, not their size, means
+ * anything. Words in the prompt steer it: "slow" adds 250 ms, "boom" returns a 500, "nousage" leaves out the usage block (as some OpenAI-compatible servers do).
+ */
+public class FakeOpenAiServer implements AutoCloseable {
+
+    private static final JsonMapper JSON = JsonMapper.builder().build();
+
+    public static final String MODEL = "gpt-4o-mini-2024-07-18";
+
+    private final HttpServer server;
+
+    private final List<String> requestBodies = new CopyOnWriteArrayList<>();
+
+    public FakeOpenAiServer(int port) throws IOException {
+        server = HttpServer.create(new InetSocketAddress("127.0.0.1", port), 0);
+        server.createContext("/chat/completions", this::handle);
+        server.createContext("/v1/chat/completions", this::handle);
+        server.start();
+    }
+
+    public int port() {
+        return server.getAddress().getPort();
+    }
+
+    public String url() {
+        return "http://127.0.0.1:" + port();
+    }
+
+    /** Raw request bodies received, oldest first. */
+    public List<String> requestBodies() {
+        return requestBodies;
+    }
+
+    @Override
+    public void close() {
+        server.stop(0);
+    }
+
+    private void handle(HttpExchange ex) throws IOException {
+        String body = new String(ex.getRequestBody().readAllBytes(), StandardCharsets.UTF_8);
+        requestBodies.add(body);
+        JsonNode req = JSON.readTree(body);
+        StringBuilder all = new StringBuilder();
+        String lastRole = "";
+        String lastUser = "";
+        for (JsonNode m : req.path("messages")) {
+            String content = m.path("content").isString() ? m.path("content").asString() : m.path("content").toString();
+            all.append(content);
+            lastRole = m.path("role").asString();
+            if (lastRole.equals("user")) {
+                lastUser = content;
+            }
+        }
+        String text = all.toString();
+        sleep(text.contains("slow") ? 250 : 30);
+        if (text.contains("boom")) {
+            send(ex, 500, "{\"error\":{\"message\":\"simulated upstream failure\",\"type\":\"server_error\"}}");
+            return;
+        }
+        int promptTokens = tokens(text);
+        boolean noUsage = text.contains("nousage");
+        boolean stream = req.path("stream").asBoolean(false);
+        boolean wantsTool = req.path("tools").size() > 0 && !lastRole.equals("tool") && lastUser.toLowerCase().contains("weather");
+        if (wantsTool) {
+            String city = lastUser.replaceAll("(?s).*weather in ([A-Za-z]+).*", "$1");
+            String message = "{\"role\":\"assistant\",\"content\":null,\"tool_calls\":[{\"id\":\"call_1\",\"type\":\"function\",\"function\":{\"name\":\"getWeather\",\"arguments\":\"{\\\"city\\\":\\\"" + city + "\\\"}\"}}]}";
+            send(ex, 200, completion(message, "tool_calls", promptTokens, 12, noUsage));
+            return;
+        }
+        String answer = lastRole.equals("tool") ? "It is 24 C and clear." : "Answer to: " + abbreviate(lastUser);
+        if (stream) {
+            streamAnswer(ex, answer, promptTokens, !noUsage && req.path("stream_options").path("include_usage").asBoolean(false));
+            return;
+        }
+        send(ex, 200, completion("{\"role\":\"assistant\",\"content\":" + JSON.writeValueAsString(answer) + "}", "stop", promptTokens, tokens(answer), noUsage));
+    }
+
+    private static String completion(String message, String finish, int in, int out, boolean noUsage) {
+        return "{\"id\":\"chatcmpl-fake\",\"object\":\"chat.completion\",\"created\":1700000000,\"model\":\"" + MODEL + "\","
+                + "\"choices\":[{\"index\":0,\"message\":" + message + ",\"finish_reason\":\"" + finish + "\"}]"
+                + (noUsage ? "" : ",\"usage\":{\"prompt_tokens\":" + in + ",\"completion_tokens\":" + out + ",\"total_tokens\":" + (in + out) + "}") + "}";
+    }
+
+    private void streamAnswer(HttpExchange ex, String answer, int promptTokens, boolean includeUsage) throws IOException {
+        ex.getResponseHeaders().add("Content-Type", "text/event-stream");
+        ex.sendResponseHeaders(200, 0);
+        List<String> parts = new ArrayList<>(List.of(answer.split("(?<= )")));
+        try (OutputStream os = ex.getResponseBody()) {
+            for (String part : parts) {
+                os.write(("data: " + chunk("{\"content\":" + JSON.writeValueAsString(part) + "}", "null", false, 0, 0) + "\n\n").getBytes(StandardCharsets.UTF_8));
+            }
+            os.write(("data: " + chunk("{}", "\"stop\"", false, 0, 0) + "\n\n").getBytes(StandardCharsets.UTF_8));
+            if (includeUsage) {
+                os.write(("data: " + chunk("{}", "null", true, promptTokens, tokens(answer)) + "\n\n").getBytes(StandardCharsets.UTF_8));
+            }
+            os.write("data: [DONE]\n\n".getBytes(StandardCharsets.UTF_8));
+        }
+    }
+
+    private static String chunk(String delta, String finish, boolean usage, int in, int out) {
+        String choices = usage ? "[]" : "[{\"index\":0,\"delta\":" + delta + ",\"finish_reason\":" + finish + "}]";
+        String u = usage ? ",\"usage\":{\"prompt_tokens\":" + in + ",\"completion_tokens\":" + out + ",\"total_tokens\":" + (in + out) + "}" : "";
+        return "{\"id\":\"chatcmpl-fake\",\"object\":\"chat.completion.chunk\",\"created\":1700000000,\"model\":\"" + MODEL + "\",\"choices\":" + choices + u + "}";
+    }
+
+    private static void send(HttpExchange ex, int status, String json) throws IOException {
+        byte[] bytes = json.getBytes(StandardCharsets.UTF_8);
+        ex.getResponseHeaders().add("Content-Type", "application/json");
+        ex.sendResponseHeaders(status, bytes.length);
+        try (OutputStream os = ex.getResponseBody()) {
+            os.write(bytes);
+        }
+    }
+
+    static int tokens(String s) {
+        return Math.max(1, (s.length() + 3) / 4);
+    }
+
+    private static String abbreviate(String s) {
+        return s.length() > 40 ? s.substring(0, 40) : s;
+    }
+
+    private static void sleep(long ms) {
+        try {
+            Thread.sleep(ms);
+        }
+        catch (InterruptedException e) {
+            Thread.currentThread().interrupt();
+        }
+    }
+
+    public static void main(String[] args) throws Exception {
+        int port = args.length > 0 ? Integer.parseInt(args[0]) : 8099;
+        new FakeOpenAiServer(port);
+        System.out.println("fake OpenAI server on " + port);
+        Thread.currentThread().join();
+    }
+}

observability/src/main/resources/application-stack.yml

@@ -0,0 +1,11 @@
+# Profile used by scripts/stack-up.sh: adds the latency histogram Grafana needs for percentiles.
+management:
+  metrics:
+    distribution:
+      percentiles-histogram:
+        gen_ai.client.operation: true
+        spring.ai.chat.client: true
+      minimum-expected-value:
+        gen_ai.client.operation: 50ms
+      maximum-expected-value:
+        gen_ai.client.operation: 30s

observability/src/main/resources/application.yml

@@ -0,0 +1,31 @@
+spring:
+  application:
+    name: spring-ai-observability
+  ai:
+    openai:
+      api-key: test-key-not-a-secret
+      base-url: ${FAKE_OPENAI_URL:http://localhost:8099}
+      chat:
+        options:
+          model: gpt-4o-mini
+management:
+  endpoints:
+    web:
+      exposure:
+        include: health,prometheus,metrics
+  tracing:
+    sampling:
+      probability: 1.0
+    export:
+      otlp:
+        enabled: false   # set true (and management.opentelemetry.tracing.export.otlp.endpoint) to ship spans to a Collector
+  otlp:
+    metrics:
+      export:
+        enabled: false   # Prometheus scrapes /actuator/prometheus instead
+ai:
+  # Illustrative prices in USD per million tokens. They are example numbers for the demo, not a current price list.
+  pricing:
+    models:
+      gpt-4o-mini: { input-per-million: 0.15, output-per-million: 0.60 }
+      gpt-4o: { input-per-million: 2.50, output-per-million: 10.00 }

observability/src/test/java/com/ankurm/observability/BuiltInMetricsTest.java

@@ -0,0 +1,63 @@
+package com.ankurm.observability;
+
+import java.util.Map;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.Obs;
+import com.ankurm.observability.support.Transcript;
+import io.micrometer.core.instrument.MeterRegistry;
+import org.junit.jupiter.api.Test;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.server.LocalServerPort;
+import org.springframework.test.context.DynamicPropertyRegistry;
+import org.springframework.test.context.DynamicPropertySource;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/**
+ * What Spring AI 2.0.1 records without any code of ours: the real OpenAiChatModel talks to a local
+ * fake server, and every meter below was created by the framework. Writes output/01.
+ */
+@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
+class BuiltInMetricsTest {
+
+    @DynamicPropertySource
+    static void fake(DynamicPropertyRegistry r) {
+        r.add("spring.ai.openai.base-url", Fake.SERVER::url);
+    }
+
+    @LocalServerPort
+    int port;
+
+    @Autowired
+    MeterRegistry registry;
+
+    @Test
+    void whatTheFrameworkRecords() {
+        RestClient http = RestClient.create("http://localhost:" + port);
+        http.get().uri("/ask?q=hello world").retrieve().body(String.class);
+        http.get().uri("/weather?city=Pune").retrieve().body(String.class);
+        http.get().uri("/stream?q=tell me").retrieve().body(String.class);
+
+        Map<String, String> fam = Obs.families(registry, "gen_ai.", "spring.ai.");
+        double in = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "input");
+        double out = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "output");
+        double total = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "total");
+
+        try (Transcript t = new Transcript("01-builtin-metrics.txt", "Meters the framework creates for 3 requests (/ask, /weather with one tool call, /stream)")) {
+            fam.forEach((name, desc) -> t.line("%-34s %s", name, desc));
+            t.blank();
+            t.line("model calls recorded (gen_ai.client.operation, error=none): %d", Obs.timerCount(registry, "gen_ai.client.operation", "error", "none"));
+            t.line("chat client calls recorded (spring.ai.chat.client): %d", Obs.timerCount(registry, "spring.ai.chat.client"));
+            t.line("tool executions recorded (spring.ai.tool): %d", Obs.timerCount(registry, "spring.ai.tool"));
+            t.line("tokens: input=%.0f output=%.0f total=%.0f", in, out, total);
+        }
+        assertThat(fam).containsKeys("gen_ai.client.operation", "gen_ai.client.token.usage", "spring.ai.chat.client", "spring.ai.tool", "spring.ai.advisor");
+        assertThat(Obs.timerCount(registry, "gen_ai.client.operation", "error", "none")).isEqualTo(4);
+        assertThat(Obs.timerCount(registry, "spring.ai.chat.client")).isEqualTo(3);
+        assertThat(Obs.timerCount(registry, "spring.ai.tool")).isEqualTo(1);
+        assertThat(total).isEqualTo(in + out);
+    }
+}

observability/src/test/java/com/ankurm/observability/CostPerEndpointTest.java

@@ -0,0 +1,67 @@
+package com.ankurm.observability;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.Obs;
+import com.ankurm.observability.support.Transcript;
+import io.micrometer.core.instrument.MeterRegistry;
+import org.junit.jupiter.api.Test;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.server.LocalServerPort;
+import org.springframework.test.context.DynamicPropertyRegistry;
+import org.springframework.test.context.DynamicPropertySource;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.within;
+
+/** Tokens and cost per endpoint from our own handler, checked against what the fake server reported. Writes output/03. */
+@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
+class CostPerEndpointTest {
+
+    @DynamicPropertySource
+    static void fake(DynamicPropertyRegistry r) {
+        r.add("spring.ai.openai.base-url", Fake.SERVER::url);
+    }
+
+    @LocalServerPort
+    int port;
+
+    @Autowired
+    MeterRegistry registry;
+
+    @Test
+    void costIsTokensTimesPriceAndSplitsByEndpoint() {
+        RestClient http = RestClient.create("http://localhost:" + port);
+        String shortText = "tiny";
+        String longText = "x".repeat(2000);
+        http.get().uri("/ask?q={q}", shortText).retrieve().body(String.class);
+        http.get().uri("/summarize?text={t}", longText).retrieve().body(String.class);
+        http.get().uri("/weather?city=Pune").retrieve().body(String.class);
+
+        try (Transcript t = new Transcript("03-cost-per-endpoint.txt", "Tokens and cost per endpoint (illustrative price: 0.15 USD in / 0.60 USD out per million tokens)")) {
+            t.line("%-10s %8s %8s %14s", "endpoint", "input", "output", "cost USD");
+            double sum = 0;
+            for (String ep : new String[] { "ask", "summarize", "weather" }) {
+                double in = Obs.counter(registry, "app.ai.tokens", "endpoint", ep, "type", "input");
+                double out = Obs.counter(registry, "app.ai.tokens", "endpoint", ep, "type", "output");
+                double cost = Obs.counter(registry, "app.ai.cost.usd", "endpoint", ep);
+                sum += cost;
+                t.line("%-10s %8.0f %8.0f %14.8f", ep, in, out, cost);
+                assertThat(cost).isCloseTo(in * 0.15 / 1e6 + out * 0.60 / 1e6, within(1e-12));
+            }
+            double modelIn = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "input");
+            double modelOut = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "output");
+            double ourIn = Obs.counter(registry, "app.ai.tokens", "type", "input");
+            double ourOut = Obs.counter(registry, "app.ai.tokens", "type", "output");
+            t.blank();
+            t.line("framework model-level tokens: input=%.0f output=%.0f", modelIn, modelOut);
+            t.line("our per-endpoint tokens     : input=%.0f output=%.0f", ourIn, ourOut);
+            t.line("total cost USD: %.8f", sum);
+            assertThat(ourIn).isEqualTo(modelIn);
+            assertThat(ourOut).isEqualTo(modelOut);
+        }
+        // The summarize endpoint sent ~2000 characters and must cost more than the one-word ask.
+        assertThat(Obs.counter(registry, "app.ai.cost.usd", "endpoint", "summarize")).isGreaterThan(Obs.counter(registry, "app.ai.cost.usd", "endpoint", "ask"));
+    }
+}

observability/src/test/java/com/ankurm/observability/ErrorAndRetryTest.java

@@ -0,0 +1,54 @@
+package com.ankurm.observability;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.Obs;
+import com.ankurm.observability.support.Transcript;
+import io.micrometer.core.instrument.MeterRegistry;
+import org.junit.jupiter.api.Test;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.server.LocalServerPort;
+import org.springframework.test.context.DynamicPropertyRegistry;
+import org.springframework.test.context.DynamicPropertySource;
+import org.springframework.web.client.HttpServerErrorException;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+import static org.assertj.core.api.Assertions.assertThatThrownBy;
+
+/** A failing provider: how many HTTP requests one call makes, what the error tag looks like, and what our cost handler does. Writes output/05. */
+@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
+class ErrorAndRetryTest {
+
+    @DynamicPropertySource
+    static void fake(DynamicPropertyRegistry r) {
+        r.add("spring.ai.openai.base-url", Fake.SERVER::url);
+    }
+
+    @LocalServerPort
+    int port;
+
+    @Autowired
+    MeterRegistry registry;
+
+    @Test
+    void oneFailedCallIsSeveralHttpRequests() {
+        RestClient http = RestClient.create("http://localhost:" + port);
+        int before = Fake.SERVER.requestBodies().size();
+        assertThatThrownBy(() -> http.get().uri("/ask?q=boom").retrieve().body(String.class)).isInstanceOf(HttpServerErrorException.class);
+        int attempts = Fake.SERVER.requestBodies().size() - before;
+
+        try (Transcript t = new Transcript("05-error-and-retry.txt", "One failed user request (the provider returns HTTP 500)")) {
+            t.line("HTTP requests the provider received for that one call: %d", attempts);
+            t.line("model-call timers recorded:");
+            registry.find("gen_ai.client.operation").timers().stream()
+                    .sorted(java.util.Comparator.comparing(x -> x.getId().getTag("error")))
+                    .forEach(x -> t.line("  error=%-24s response.model=%-24s count=%d", x.getId().getTag("error"), x.getId().getTag("gen_ai.response.model"), x.count()));
+            t.line("chat-client timers with an error: %d", registry.find("spring.ai.chat.client").tag("error", "InternalServerException").timers().size());
+            t.line("app.ai.unpriced{endpoint=ask,reason=no-usage}: %.0f", Obs.counter(registry, "app.ai.unpriced", "endpoint", "ask", "reason", "no-usage"));
+            t.line("app.ai.cost.usd recorded for the failed call: %.0f", Obs.counter(registry, "app.ai.cost.usd", "endpoint", "ask"));
+        }
+        assertThat(attempts).isGreaterThan(1);
+        assertThat(Obs.timerCount(registry, "gen_ai.client.operation", "error", "InternalServerException")).isEqualTo(1);
+    }
+}

observability/src/test/java/com/ankurm/observability/HistogramTest.java

@@ -0,0 +1,61 @@
+package com.ankurm.observability;
+
+import java.util.Arrays;
+import java.util.List;
+import java.util.stream.Stream;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.Transcript;
+import org.junit.jupiter.api.Test;
+import org.springframework.boot.WebApplicationType;
+import org.springframework.boot.builder.SpringApplicationBuilder;
+import org.springframework.boot.web.server.context.WebServerApplicationContext;
+import org.springframework.context.ConfigurableApplicationContext;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/**
+ * Timers carry no histogram buckets unless asked, so histogram_quantile() has nothing to work with.
+ * Starts the app twice, scrapes /actuator/prometheus and counts the bucket series. Writes output/07.
+ */
+class HistogramTest {
+
+    private static final String METER = "gen_ai_client_operation_seconds";
+
+    private record Scrape(long buckets, long sumLines, String firstBucket) {
+    }
+
+    private static Scrape run(String... props) {
+        String[] args = Stream.concat(Stream.of("spring.ai.openai.base-url=" + Fake.SERVER.url(), "server.port=0"), Arrays.stream(props))
+                .map(a -> "--" + a).toArray(String[]::new);
+        try (ConfigurableApplicationContext ctx = new SpringApplicationBuilder(ObservabilityApplication.class)
+                .web(WebApplicationType.SERVLET).run(args)) {
+            int port = ((WebServerApplicationContext) ctx).getWebServer().getPort();
+            RestClient http = RestClient.create("http://localhost:" + port);
+            http.get().uri("/ask?q=hello").retrieve().body(String.class);
+            http.get().uri("/ask?q=slow one").retrieve().body(String.class);
+            String body = http.get().uri("/actuator/prometheus").retrieve().body(String.class);
+            List<String> lines = body.lines().filter(l -> l.startsWith(METER)).toList();
+            List<String> buckets = lines.stream().filter(l -> l.startsWith(METER + "_bucket")).toList();
+            return new Scrape(buckets.size(), lines.stream().filter(l -> l.startsWith(METER + "_sum")).count(),
+                    buckets.isEmpty() ? "-" : buckets.get(0).replaceAll("\\{.*le=\"([^\"]+)\".*}", "{le=\"$1\"}").replaceAll(" .*", ""));
+        }
+    }
+
+    @Test
+    void bucketsAreOptIn() {
+        Scrape off = run();
+        Scrape on = run("management.metrics.distribution.percentiles-histogram.gen_ai.client.operation=true");
+        try (Transcript t = new Transcript("07-histogram.txt", "Bucket series for " + METER + " after 2 calls")) {
+            t.line("%-70s %s", "setting", "_bucket series / _sum series");
+            t.line("%-70s %d / %d", "defaults", off.buckets(), off.sumLines());
+            t.line("%-70s %d / %d", "percentiles-histogram.gen_ai.client.operation=true", on.buckets(), on.sumLines());
+            t.blank();
+            t.line("first bucket series when enabled: %s", on.firstBucket());
+        }
+        assertThat(off.buckets()).isZero();
+        assertThat(off.sumLines()).isPositive();
+        assertThat(on.buckets()).isGreaterThan(10);
+    }
+}

observability/src/test/java/com/ankurm/observability/PromptContentTest.java

@@ -0,0 +1,80 @@
+package com.ankurm.observability;
+
+import java.util.ArrayList;
+import java.util.List;
+
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.read.ListAppender;
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.TestObs;
+import com.ankurm.observability.support.Transcript;
+import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter;
+import io.opentelemetry.sdk.trace.data.SpanData;
+import org.junit.jupiter.api.Test;
+import org.slf4j.LoggerFactory;
+import org.springframework.boot.WebApplicationType;
+import org.springframework.boot.builder.SpringApplicationBuilder;
+import org.springframework.context.ConfigurableApplicationContext;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/** Is the prompt text in your telemetry? By default no; two properties put it there. Writes output/06. */
+class PromptContentTest {
+
+    private static final String SECRET = "ticket-4711-card-ending-0042";
+
+    private record Result(int logLines, List<String> spanAttributesWithSecret, int spanEventsWithSecret) {
+    }
+
+    private static Result run(String... props) {
+        ListAppender<ILoggingEvent> appender = new ListAppender<>();
+        appender.start();
+        Logger root = null;
+        List<String> all = new ArrayList<>(List.of("spring.ai.openai.base-url=" + Fake.SERVER.url(), "server.port=0"));
+        all.addAll(List.of(props));
+        try (ConfigurableApplicationContext ctx = new SpringApplicationBuilder(ObservabilityApplication.class, TestObs.class)
+                .web(WebApplicationType.SERVLET).run(all.stream().map(a -> "--" + a).toArray(String[]::new))) {
+            // Spring Boot re-initialises logging while the context starts and would drop an appender attached earlier.
+            root = (Logger) LoggerFactory.getLogger("org.springframework.ai");
+            root.addAppender(appender);
+            ctx.getBean(AiController.class).ask(SECRET);
+            InMemorySpanExporter exporter = ctx.getBean(InMemorySpanExporter.class);
+            List<String> attrs = new ArrayList<>();
+            int events = 0;
+            for (SpanData s : exporter.getFinishedSpanItems()) {
+                s.getAttributes().forEach((k, v) -> {
+                    if (String.valueOf(v).contains(SECRET)) {
+                        attrs.add(s.getName() + " -> " + k.getKey());
+                    }
+                });
+                events += (int) s.getEvents().stream().filter(e -> e.getAttributes().asMap().values().stream().anyMatch(v -> String.valueOf(v).contains(SECRET))).count();
+            }
+            long logs = appender.list.stream().filter(e -> e.getFormattedMessage().contains(SECRET)).count();
+            return new Result((int) logs, attrs.stream().sorted().toList(), events);
+        }
+        finally {
+            if (root != null) {
+                root.detachAppender(appender);
+            }
+        }
+    }
+
+    @Test
+    void promptTextIsOffByDefault() {
+        Result off = run();
+        Result on = run("spring.ai.chat.observations.log-prompt=true", "spring.ai.chat.client.observations.log-prompt=true");
+
+        try (Transcript t = new Transcript("06-prompt-content.txt", "Where does the prompt text \"" + SECRET + "\" appear in telemetry?")) {
+            t.line("%-62s %s", "setting", "log lines with it / span attributes with it / span events with it");
+            t.line("%-62s %d / %d / %d", "defaults", off.logLines(), off.spanAttributesWithSecret().size(), off.spanEventsWithSecret());
+            t.line("%-62s %d / %d / %d", "spring.ai.chat.observations.log-prompt=true (+ client)", on.logLines(), on.spanAttributesWithSecret().size(), on.spanEventsWithSecret());
+            t.line("");
+            t.line("span attributes carrying the text when enabled: %s", on.spanAttributesWithSecret());
+        }
+        assertThat(off.logLines()).isZero();
+        assertThat(off.spanAttributesWithSecret()).isEmpty();
+        assertThat(off.spanEventsWithSecret()).isZero();
+        assertThat(on.logLines() + on.spanAttributesWithSecret().size() + on.spanEventsWithSecret()).isPositive();
+    }
+}

observability/src/test/java/com/ankurm/observability/StreamingUsageTest.java

@@ -0,0 +1,59 @@
+package com.ankurm.observability;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.Obs;
+import com.ankurm.observability.support.Transcript;
+import io.micrometer.core.instrument.MeterRegistry;
+import org.junit.jupiter.api.Test;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.server.LocalServerPort;
+import org.springframework.test.context.DynamicPropertyRegistry;
+import org.springframework.test.context.DynamicPropertySource;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/** Streaming responses and missing usage: what the request asks for, and what happens when a server leaves usage out. Writes output/04. */
+@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
+class StreamingUsageTest {
+
+    @DynamicPropertySource
+    static void fake(DynamicPropertyRegistry r) {
+        r.add("spring.ai.openai.base-url", Fake.SERVER::url);
+    }
+
+    @LocalServerPort
+    int port;
+
+    @Autowired
+    MeterRegistry registry;
+
+    @Test
+    void streamingRequestsUsageAndAMissingUsageBlockIsCountedNotIgnored() {
+        RestClient http = RestClient.create("http://localhost:" + port);
+        int before = Fake.SERVER.requestBodies().size();
+        http.get().uri("/stream?q=tell me").retrieve().body(String.class);
+        String streamRequest = Fake.SERVER.requestBodies().get(before);
+
+        double tokensBefore = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "total");
+        http.get().uri("/ask?q=nousage please").retrieve().body(String.class);
+        http.get().uri("/stream?q=nousage please").retrieve().body(String.class);
+        double tokensAfter = Obs.counter(registry, "gen_ai.client.token.usage", "gen_ai.token.type", "total");
+
+        boolean asksForUsage = streamRequest.replace(" ", "").contains("\"stream_options\":{\"include_usage\":true");
+        try (Transcript t = new Transcript("04-streaming-usage.txt", "Streaming asks for usage; a server that omits it is counted as unpriced")) {
+            t.line("stream request body asks for usage (stream_options.include_usage): %s", asksForUsage);
+            t.line("request fragment: %s", streamRequest.replaceAll(".*(\"stream\":true).*", "$1"));
+            t.line("");
+            t.line("two calls to a server that omits the usage block (/ask and /stream):");
+            t.line("  gen_ai.client.token.usage total, before %.0f -> after %.0f", tokensBefore, tokensAfter);
+            t.line("  app.ai.unpriced{reason=no-usage} for ask   : %.0f", Obs.counter(registry, "app.ai.unpriced", "endpoint", "ask", "reason", "no-usage"));
+            t.line("  app.ai.unpriced{reason=no-usage} for stream: %.0f", Obs.counter(registry, "app.ai.unpriced", "endpoint", "stream", "reason", "no-usage"));
+        }
+        assertThat(asksForUsage).isTrue();
+        assertThat(tokensAfter).isEqualTo(tokensBefore);
+        assertThat(Obs.counter(registry, "app.ai.unpriced", "endpoint", "ask", "reason", "no-usage")).isEqualTo(1);
+        assertThat(Obs.counter(registry, "app.ai.unpriced", "endpoint", "stream", "reason", "no-usage")).isEqualTo(1);
+    }
+}

observability/src/test/java/com/ankurm/observability/ToolCallSpansTest.java

@@ -0,0 +1,74 @@
+package com.ankurm.observability;
+
+import java.util.ArrayList;
+import java.util.Comparator;
+import java.util.List;
+import java.util.Map;
+import java.util.stream.Collectors;
+
+import com.ankurm.observability.support.Fake;
+import com.ankurm.observability.support.TestObs;
+import com.ankurm.observability.support.Transcript;
+import io.opentelemetry.api.common.AttributeKey;
+import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter;
+import io.opentelemetry.sdk.trace.data.SpanData;
+import org.junit.jupiter.api.Test;
+import org.springframework.beans.factory.annotation.Autowired;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.web.server.LocalServerPort;
+import org.springframework.context.annotation.Import;
+import org.springframework.test.context.DynamicPropertyRegistry;
+import org.springframework.test.context.DynamicPropertySource;
+import org.springframework.web.client.RestClient;
+
+import static org.assertj.core.api.Assertions.assertThat;
+
+/** The trace of one tool-calling request, read from an in-memory OpenTelemetry exporter. Writes output/02. */
+@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.RANDOM_PORT)
+@Import(TestObs.class)
+class ToolCallSpansTest {
+
+    @DynamicPropertySource
+    static void fake(DynamicPropertyRegistry r) {
+        r.add("spring.ai.openai.base-url", Fake.SERVER::url);
+    }
+
+    @LocalServerPort
+    int port;
+
+    @Autowired
+    InMemorySpanExporter exporter;
+
+    @Test
+    void oneToolCallingRequestIsOneTree() {
+        exporter.reset();
+        RestClient.create("http://localhost:" + port).get().uri("/weather?city=Pune").retrieve().body(String.class);
+
+        // The server span ends after the response has been written, so the client can get its answer first.
+        org.awaitility.Awaitility.await().atMost(java.time.Duration.ofSeconds(5)).until(
+                () -> exporter.getFinishedSpanItems().stream().anyMatch(s -> s.getName().equals("http get /weather")));
+        List<SpanData> spans = new ArrayList<>(exporter.getFinishedSpanItems());
+        // Drop the spans that are not part of this request's tree (there are none expected, but be explicit).
+        spans.sort(Comparator.comparingLong(SpanData::getStartEpochNanos));
+        Map<String, SpanData> byId = spans.stream().collect(Collectors.toMap(s -> s.getSpanId(), s -> s));
+
+        try (Transcript t = new Transcript("02-tool-call-spans.txt", "Span tree for GET /weather?city=Pune (one tool call, two model calls)")) {
+            for (SpanData s : spans) {
+                int depth = 0;
+                SpanData p = byId.get(s.getParentSpanId());
+                while (p != null) {
+                    depth++;
+                    p = byId.get(p.getParentSpanId());
+                }
+                t.line("%s%s  [%s]", "  ".repeat(depth), s.getName(), s.getKind());
+            }
+            t.blank();
+            t.line("attribute keys on the model-call spans:");
+            spans.stream().filter(s -> s.getName().startsWith("chat")).findFirst().ifPresent(s ->
+                    s.getAttributes().asMap().keySet().stream().map(AttributeKey::getKey).sorted().forEach(k -> t.line("  %s", k)));
+        }
+        assertThat(spans).extracting(SpanData::getName).contains("spring_ai chat_client", "execute_tool getWeather");
+        assertThat(spans.stream().filter(s -> s.getName().startsWith("chat ")).count()).isEqualTo(2);
+        assertThat(spans.stream().map(SpanData::getTraceId).distinct().count()).isEqualTo(1);
+    }
+}

observability/src/test/java/com/ankurm/observability/support/Fake.java

@@ -0,0 +1,23 @@
+package com.ankurm.observability.support;
+
+import java.io.IOException;
+
+import com.ankurm.observability.fake.FakeOpenAiServer;
+
+/** One fake OpenAI server for the whole test JVM, so every Spring context can point at it. */
+public final class Fake {
+
+    public static final FakeOpenAiServer SERVER = start();
+
+    private Fake() {
+    }
+
+    private static FakeOpenAiServer start() {
+        try {
+            return new FakeOpenAiServer(0);
+        }
+        catch (IOException e) {
+            throw new IllegalStateException(e);
+        }
+    }
+}

observability/src/test/java/com/ankurm/observability/support/Obs.java

@@ -0,0 +1,47 @@
+package com.ankurm.observability.support;
+
+import java.util.Comparator;
+import java.util.List;
+import java.util.Map;
+import java.util.TreeMap;
+import java.util.stream.Collectors;
+
+import io.micrometer.core.instrument.Meter;
+import io.micrometer.core.instrument.MeterRegistry;
+import io.micrometer.core.instrument.Tag;
+
+/** Small helpers for reading a MeterRegistry in tests. */
+public final class Obs {
+
+    private Obs() {
+    }
+
+    /** Sum of the counters with this name whose tags include all the given key/value pairs. */
+    public static double counter(MeterRegistry registry, String name, String... tagPairs) {
+        return registry.find(name).tags(tagPairs).counters().stream().mapToDouble(c -> c.count()).sum();
+    }
+
+    /** Number of recordings of the timers with this name whose tags include all the given pairs. */
+    public static long timerCount(MeterRegistry registry, String name, String... tagPairs) {
+        return registry.find(name).tags(tagPairs).timers().stream().mapToLong(t -> t.count()).sum();
+    }
+
+    /** One line per meter name starting with a prefix: name, type, and the sorted tag keys. */
+    public static Map<String, String> families(MeterRegistry registry, String... prefixes) {
+        Map<String, String> out = new TreeMap<>();
+        for (Meter m : registry.getMeters()) {
+            String name = m.getId().getName();
+            for (String p : prefixes) {
+                if (name.startsWith(p)) {
+                    String keys = m.getId().getTags().stream().map(Tag::getKey).sorted().collect(Collectors.joining(", "));
+                    out.merge(name, m.getId().getType() + "  [" + keys + "]", (a, b) -> a.length() >= b.length() ? a : b);
+                }
+            }
+        }
+        return out;
+    }
+
+    public static List<String> names(MeterRegistry registry, String prefix) {
+        return registry.getMeters().stream().map(m -> m.getId().getName()).filter(n -> n.startsWith(prefix)).distinct().sorted(Comparator.naturalOrder()).toList();
+    }
+}

observability/src/test/java/com/ankurm/observability/support/TestObs.java

@@ -0,0 +1,22 @@
+package com.ankurm.observability.support;
+
+import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter;
+import io.opentelemetry.sdk.trace.SpanProcessor;
+import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor;
+import org.springframework.boot.test.context.TestConfiguration;
+import org.springframework.context.annotation.Bean;
+
+/** Captures finished spans in memory (synchronously) so a test can read the span tree. */
+@TestConfiguration
+public class TestObs {
+
+    @Bean
+    InMemorySpanExporter inMemorySpanExporter() {
+        return InMemorySpanExporter.create();
+    }
+
+    @Bean
+    SpanProcessor simpleSpanProcessor(InMemorySpanExporter exporter) {
+        return SimpleSpanProcessor.create(exporter);
+    }
+}

observability/src/test/java/com/ankurm/observability/support/Transcript.java

@@ -0,0 +1,47 @@
+package com.ankurm.observability.support;
+
+import java.io.IOException;
+import java.io.PrintWriter;
+import java.io.StringWriter;
+import java.nio.file.Files;
+import java.nio.file.Path;
+
+/**
+ * Writes a numbered transcript under {@code output/} (repository root, not {@code docs/}) and
+ * echoes it to the console. Every console block quoted in the article comes out of one of these
+ * files verbatim.
+ */
+public final class Transcript implements AutoCloseable {
+
+    private final Path path;
+    private final StringWriter buffer = new StringWriter();
+    private final PrintWriter out = new PrintWriter(buffer);
+
+    public Transcript(String fileName, String title) {
+        this.path = Path.of("output", fileName);
+        out.println("# " + title);
+        out.println();
+    }
+
+    public Transcript line(String format, Object... args) {
+        out.println(args.length == 0 ? format : String.format(format, args));
+        return this;
+    }
+
+    public Transcript blank() {
+        out.println();
+        return this;
+    }
+
+    @Override
+    public void close() {
+        out.flush();
+        try {
+            Files.createDirectories(path.getParent());
+            Files.writeString(path, buffer.toString());
+        } catch (IOException e) {
+            throw new IllegalStateException("could not write " + path, e);
+        }
+        System.out.print(buffer);
+    }
+}