From 99f40cdb3ac8041d4f03577d5680f68c8b8d0261 Mon Sep 17 00:00:00 2001 From: Alex Johnson Date: Sat, 19 Sep 2026 21:23:53 -0400 Subject: [PATCH 1/5] Log requests through slf4j, with credential headers masked INFO is one line per request with its status and how long it took, plus a line for each retry and each connection failure. DEBUG adds the wire in both directions: method, url, headers and body. Nothing at WARN or above, because a failure is already thrown and the exception carries more than a log line would. The tiering follows the official Python and JavaScript SDKs. There is no TYPESAFE_LOG_LEVEL. slf4j has no library-side level setting, and configuring the logging environment is the application's job; the level is set on the io.github.premocloud.typesafe logger like any other library's. Redaction happens in one method, so no call site can leak a credential. The named header set is the union of what the two official SDKs cover, plus a substring check for token and secret, since Builder.header lets a caller add one this SDK never anticipated. The wire calls are guarded by isDebugEnabled so the redacted string is not built when the level is off. Adds five tests covering the level tiering, the wire in both directions, the retry line, silence above INFO, and that the key never appears in any message. --- CHANGELOG.md | 4 + README.md | 31 ++++- typesafe-sdk/build.gradle.kts | 4 + .../github/premocloud/typesafe/Logging.java | 78 +++++++++++ .../premocloud/typesafe/TypeSafeClient.java | 52 ++++++-- .../premocloud/typesafe/LoggingTest.java | 124 ++++++++++++++++++ 6 files changed, 283 insertions(+), 10 deletions(-) create mode 100644 typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java create mode 100644 typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java diff --git a/CHANGELOG.md b/CHANGELOG.md index c82ba2e..a0c3aaa 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,9 @@ # Changelog +## Unreleased + +- Logging through slf4j on the `io.github.premocloud.typesafe` logger: `INFO` for one line per request with status and elapsed, plus retries and connection failures; `DEBUG` for the wire in both directions. Credential headers are masked. Adds `org.slf4j:slf4j-api` (#6). + ## 0.3.0 - 2026-09-19 - Async API: `systemOneAsync` mirroring every `systemOne` overload and `models().listAsync()` return `CompletableFuture`s driven by `HttpClient.sendAsync`, so retries back off without holding a thread, honoring the same per-call `RequestOptions` and failing with the same `TypeSafeException` subclasses as the blocking calls (#4). diff --git a/README.md b/README.md index 428e90a..47a2535 100644 --- a/README.md +++ b/README.md @@ -8,7 +8,7 @@ TypeSafe AI. It follows the conventions of the official [Python](https://github. [JavaScript](https://github.com/typesafe-ai/typesafe-sdk-js) SDKs so the three read alike. TypeSafe is a trademark of its owner; the name is used here only to describe what the library connects to. -Requires Java 17 or newer. Depends only on Jackson. +Requires Java 17 or newer. Depends on Jackson and slf4j-api, plus JSpecify's nullness annotations. ## Install @@ -173,6 +173,35 @@ TypeSafeClient client = TypeSafeClient.builder() .build(); ``` +## Logging + +The client logs through slf4j on the `io.github.premocloud.typesafe` logger. Set its level the way you set any +library's; there is no environment variable, because slf4j has no library-side level setting and configuring the +logging environment is the application's job. + +| Level | What you get | +| --- | --- | +| `INFO` | one line per request with its status and how long it took, plus a line per retry and per connection failure | +| `DEBUG` | the above, plus the wire in both directions: method, url, headers, body | +| `WARN` and above | nothing; failures are thrown, not logged | + +```xml + +``` + +```properties +logging.level.io.github.premocloud.typesafe=DEBUG +``` + +``` +DEBUG io.github.premocloud.typesafe - req-1 -> POST https://api.typesafe.ai/v1/systemone headers={Authorization=***, ...} body={"state":...} +INFO io.github.premocloud.typesafe - req-1 <- 200 in 214ms +DEBUG io.github.premocloud.typesafe - req-1 <- 200 headers={x-typesafe-request-id=req_01a0..., ...} body={"model":"jev-1.13.0",...} +``` + +Credential headers are masked, including any of your own containing `token` or `secret`. **Bodies are not masked**, so +`DEBUG` puts the state you are classifying into the log. + ## Spring Boot Add `io.github.premo-cloud:typesafe-sdk-spring-boot-starter` and set one property: diff --git a/typesafe-sdk/build.gradle.kts b/typesafe-sdk/build.gradle.kts index 4bbc3fe..bb1a4ef 100644 --- a/typesafe-sdk/build.gradle.kts +++ b/typesafe-sdk/build.gradle.kts @@ -3,9 +3,12 @@ description = "Community Java client for the TypeSafe System One API" dependencies { api("com.fasterxml.jackson.core:jackson-databind:2.15.4") api("org.jspecify:jspecify:1.0.1") + api("org.slf4j:slf4j-api:2.0.16") testImplementation(platform("org.junit:junit-bom:5.14.4")) testImplementation("org.junit.jupiter:junit-jupiter") + // A binding with a programmable appender, so the tests can assert on what was logged. + testImplementation("ch.qos.logback:logback-classic:1.5.18") testRuntimeOnly("org.junit.platform:junit-platform-launcher") } @@ -17,3 +20,4 @@ mavenPublishing { description.set(project.description) } } + diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java new file mode 100644 index 0000000..5def612 --- /dev/null +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java @@ -0,0 +1,78 @@ +package io.github.premocloud.typesafe; + +import org.jspecify.annotations.Nullable; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import java.net.http.HttpHeaders; +import java.util.List; +import java.util.Locale; +import java.util.Set; +import java.util.stream.Collectors; + +/** + * What the client logs, tiered as the official SDKs log it. + * + *

{@code INFO} is one line per request with its status and how long it took, plus a line for each + * retry and each connection failure. {@code DEBUG} adds the wire in both directions: method, url, + * headers and body. Nothing is logged at {@code WARN} or above, because a failure is already thrown + * and the exception carries more than a log line would. + * + *

Set the level on the {@code io.github.premocloud.typesafe} logger, as for any library. There is + * no environment variable: slf4j has no library-side level setting, and a library should let the + * application configure its own logging. + * + *

Credential headers are masked. Bodies are not, so {@code DEBUG} puts the state being classified + * into the log; both official SDKs document the same. + */ +final class Logging { + + private static final Logger LOG = LoggerFactory.getLogger("io.github.premocloud.typesafe"); + + /** Masked in full. The union of what the official Python and JavaScript SDKs cover. */ + private static final Set SECRET_HEADERS = Set.of( + "authorization", "proxy-authorization", "api-key", "x-api-key", "cookie", "set-cookie"); + + private Logging() { + } + + static void info(String format, Object... arguments) { + LOG.info(format, arguments); + } + + /** Guards the wire calls, so a redacted header string is never built when DEBUG is off. */ + static boolean wireEnabled() { + return LOG.isDebugEnabled(); + } + + /** + * One direction of the exchange. + * + * @param arrow {@code ->} for what was sent, {@code <-} for what came back + */ + static void wire(String tag, String arrow, String summary, HttpHeaders headers, @Nullable String body) { + LOG.debug("{} {} {} headers={} body={}", tag, arrow, summary, redact(headers), body == null ? "" : body); + } + + /** + * Header names and values with credentials masked. The only place redaction happens, so no call + * site can leak one. + */ + private static String redact(HttpHeaders headers) { + return headers.map().entrySet().stream() + .map(header -> header.getKey() + "=" + value(header.getKey(), header.getValue())) + .collect(Collectors.joining(", ", "{", "}")); + } + + private static String value(String name, List values) { + String lower = name.toLowerCase(Locale.ROOT); + + // The named set covers what is documented; the substring check catches a header this SDK + // never anticipated, which a caller can add through Builder.header. + if (SECRET_HEADERS.contains(lower) || lower.contains("token") || lower.contains("secret")) { + return "***"; + } + + return values.isEmpty() ? "" : values.get(0); + } +} diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java index b872429..60cee6e 100644 --- a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java @@ -25,6 +25,7 @@ import java.util.concurrent.ExecutionException; import java.util.concurrent.ThreadLocalRandom; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicLong; import java.util.function.Consumer; /** @@ -58,6 +59,7 @@ public final class TypeSafeClient { private final HttpClient httpClient; private final ObjectMapper objectMapper; + private static final AtomicLong REQUESTS = new AtomicLong(); private final String apiKey; private final String baseUrl; private final String defaultModel; @@ -192,10 +194,18 @@ private CompletableFuture postAsync(String path, Object body, Class ty return sendAsync(HttpRequest.newBuilder(URI.create(baseUrl + path)) .header("Content-Type", "application/json") - .POST(HttpRequest.BodyPublishers.ofString(json)), type, options); + .POST(HttpRequest.BodyPublishers.ofString(json)), type, options, json); + } + + /** What logging needs about one request, the same for every attempt it makes. */ + private record Call(String tag, @Nullable String requestBody) { } private CompletableFuture sendAsync(HttpRequest.Builder template, Class type, RequestOptions options) { + return sendAsync(template, type, options, null); + } + + private CompletableFuture sendAsync(HttpRequest.Builder template, Class type, RequestOptions options, @Nullable String requestBody) { Duration timeout = Objects.requireNonNullElse(options.timeout(), this.timeout); RetryPolicy retryPolicy = options.resolveRetryPolicy(this.retryPolicy); Map headers = new LinkedHashMap<>(defaultHeaders); @@ -208,13 +218,21 @@ private CompletableFuture sendAsync(HttpRequest.Builder template, Class CompletableFuture attemptAsync(HttpRequest.Builder template, Class type, Duration timeout, RetryPolicy retryPolicy, int attempt) { + private CompletableFuture attemptAsync(HttpRequest.Builder template, Class type, Duration timeout, RetryPolicy retryPolicy, int attempt, Call call) { // Setup throws here (a bad URI, a closed client) propagate synchronously, as HttpClient.sendAsync does. HttpRequest httpRequest = attempt == 0 ? template.build() : template.copy().header(RETRY_COUNT_HEADER, Integer.toString(attempt)).build(); + + if (Logging.wireEnabled()) { + Logging.wire(call.tag(), "->", httpRequest.method() + " " + httpRequest.uri(), + httpRequest.headers(), call.requestBody()); + } + + long startedNanos = System.nanoTime(); CompletableFuture> sent = httpClient.sendAsync(httpRequest, HttpResponse.BodyHandlers.ofString()); return sent.>handle((response, error) -> { @@ -223,16 +241,20 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas Throwable cause = unwrap(error); if (cause instanceof HttpTimeoutException httpTimeout) { + Logging.info("{} timed out after {}ms", call.tag(), elapsedMs(startedNanos)); + if (retryPolicy.retryTimeouts() && attempt < retryPolicy.maxRetries()) { - return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1); + return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); } return CompletableFuture.failedFuture(new TypeSafeTimeoutException(timeout, httpTimeout)); } if (cause instanceof IOException ioException) { + Logging.info("{} <- {} after {}ms", call.tag(), ioException.getClass().getSimpleName(), elapsedMs(startedNanos)); + if (retryPolicy.retryConnectionErrors() && attempt < retryPolicy.maxRetries()) { - return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1); + return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); } return CompletableFuture.failedFuture(new TypeSafeConnectionException("Connection error: " + ioException.getMessage(), ioException)); @@ -242,14 +264,22 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } int status = response.statusCode(); + Logging.info("{} <- {} in {}ms", call.tag(), status, elapsedMs(startedNanos)); + + if (Logging.wireEnabled()) { + Logging.wire(call.tag(), "<-", String.valueOf(status), response.headers(), response.body()); + } if (status >= 200 && status < 300) { return CompletableFuture.completedFuture(deserialize(response.body(), type)); } if (retryPolicy.retriesStatus(status) && attempt < retryPolicy.maxRetries()) { - return retryAsync(backoff(retryPolicy, attempt, retryPolicy.respectRetryAfter() ? RetryAfter.parse(response.headers()) : Optional.empty()), - template, type, timeout, retryPolicy, attempt + 1); + Duration delay = backoff(retryPolicy, attempt, retryPolicy.respectRetryAfter() ? RetryAfter.parse(response.headers()) : Optional.empty()); + Logging.info("{} retrying in {}ms (retry {}/{}) after {}", call.tag(), delay.toMillis(), + attempt + 1, retryPolicy.maxRetries(), status); + + return retryAsync(delay, template, type, timeout, retryPolicy, attempt + 1, call); } return CompletableFuture.failedFuture(TypeSafeApiException.fromResponse(status, response.body(), response.headers())); @@ -260,8 +290,8 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } /** Schedules the next attempt on the JDK's shared delayer, so backoff never parks a thread of ours. */ - private CompletableFuture retryAsync(Duration delay, HttpRequest.Builder template, Class type, Duration timeout, RetryPolicy retryPolicy, int attempt) { - return CompletableFuture.supplyAsync(() -> attemptAsync(template, type, timeout, retryPolicy, attempt), + private CompletableFuture retryAsync(Duration delay, HttpRequest.Builder template, Class type, Duration timeout, RetryPolicy retryPolicy, int attempt, Call call) { + return CompletableFuture.supplyAsync(() -> attemptAsync(template, type, timeout, retryPolicy, attempt, call), CompletableFuture.delayedExecutor(delay.toMillis(), TimeUnit.MILLISECONDS)) .thenCompose(next -> next); } @@ -292,6 +322,10 @@ static T blocking(CompletableFuture future) { } } + private static long elapsedMs(long startedNanos) { + return (System.nanoTime() - startedNanos) / 1_000_000; + } + /** Completion and execution futures wrap the thrown exception; walk down to the one the caller should see. */ private static Throwable unwrap(Throwable error) { Throwable cause = error; diff --git a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java new file mode 100644 index 0000000..eb0c893 --- /dev/null +++ b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java @@ -0,0 +1,124 @@ +package io.github.premocloud.typesafe; + +import ch.qos.logback.classic.Level; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.spi.ILoggingEvent; +import ch.qos.logback.core.read.ListAppender; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; +import org.slf4j.LoggerFactory; + +import java.io.IOException; +import java.time.Duration; +import java.util.List; +import java.util.Map; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertTrue; + +/** What the client logs, at which level, and what it never puts in a log line. */ +class LoggingTest { + + private static final String API_KEY = "apik-secret-value-1234"; + + private static final String RESPONSE_JSON = """ + {"model": "jev-1.13.0", + "answers": {"q": {"type": "noul", "noul": 0.93}}, + "usage": {"input_tokens": 12, "output_tokens": 3}} + """; + + private StubTypeSafeServer server; + private ListAppender appender; + private ch.qos.logback.classic.Logger logger; + + @BeforeEach + void setUp() throws IOException { + server = new StubTypeSafeServer(); + + LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); + logger = context.getLogger("io.github.premocloud.typesafe"); + appender = new ListAppender<>(); + appender.setContext(context); + appender.start(); + logger.addAppender(appender); + logger.setLevel(Level.DEBUG); + } + + @AfterEach + void tearDown() { + logger.detachAppender(appender); + logger.setLevel(null); + server.close(); + } + + @Test + void logsOneInfoLinePerRequestWithStatusAndElapsed() { + server.reply(200, RESPONSE_JSON); + + client().systemOne("state", Map.of("q", Noul.of("Yes?"))); + + List info = messagesAt(Level.INFO); + assertEquals(1, info.size(), info.toString()); + assertTrue(info.get(0).matches(".*<- 200 in \\d+ms.*"), info.get(0)); + } + + @Test + void logsTheWireInBothDirectionsAtDebug() { + server.reply(200, RESPONSE_JSON); + + client().systemOne("state", Map.of("q", Noul.of("Yes?"))); + + List debug = messagesAt(Level.DEBUG); + assertEquals(2, debug.size(), debug.toString()); + assertTrue(debug.get(0).contains("-> POST"), debug.get(0)); + assertTrue(debug.get(1).contains("<-"), debug.get(1)); + assertTrue(debug.get(1).contains("jev-1.13.0"), "response body is logged: " + debug.get(1)); + } + + @Test + void neverLogsTheApiKey() { + server.reply(200, RESPONSE_JSON); + + client().systemOne("state", Map.of("q", Noul.of("Yes?"))); + + String everything = String.join("\n", messagesAt(null)); + assertFalse(everything.contains(API_KEY), "the key leaked: " + everything); + assertTrue(everything.contains("Authorization=***"), everything); + } + + @Test + void logsARetryLineAtInfo() { + server.reply(429, "{}", Map.of("retry-after-ms", "1")); + server.reply(200, RESPONSE_JSON); + + client().systemOne("state", Map.of("q", Noul.of("Yes?"))); + + assertTrue(messagesAt(Level.INFO).stream().anyMatch(m -> m.contains("retrying in")), + messagesAt(Level.INFO).toString()); + } + + @Test + void logsNothingWhenTheLevelIsAboveInfo() { + logger.setLevel(Level.WARN); + server.reply(200, RESPONSE_JSON); + + client().systemOne("state", Map.of("q", Noul.of("Yes?"))); + + assertEquals(List.of(), messagesAt(null)); + } + + private TypeSafeClient client() { + return TypeSafeClient.builder().apiKey(API_KEY).baseUrl(server.baseUrl()) + .timeout(Duration.ofSeconds(5)).build(); + } + + /** Formatted messages at one level, or every level when {@code level} is null. */ + private List messagesAt(Level level) { + return appender.list.stream() + .filter(event -> level == null || event.getLevel().equals(level)) + .map(ILoggingEvent::getFormattedMessage) + .toList(); + } +} From 9a3ce73ea77c11114876f1c1d44f35a235c9dba4 Mon Sep 17 00:00:00 2001 From: Alex Johnson Date: Sat, 19 Sep 2026 21:27:07 -0400 Subject: [PATCH 2/5] Keep the logging test's events out of the console The capturing appender asserts on what was logged, but additivity also sent every event to logback's default console appender, so each run printed the request and response bodies. --- .../test/java/io/github/premocloud/typesafe/LoggingTest.java | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java index eb0c893..7f92ad7 100644 --- a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java +++ b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java @@ -44,12 +44,16 @@ void setUp() throws IOException { appender.start(); logger.addAppender(appender); logger.setLevel(Level.DEBUG); + // Capture only: without this the events also reach logback's default console appender and + // every test run prints the request and response bodies. + logger.setAdditive(false); } @AfterEach void tearDown() { logger.detachAppender(appender); logger.setLevel(null); + logger.setAdditive(true); server.close(); } From 28a59062e6ebb66d2315ba9b77265eab486b7d28 Mon Sep 17 00:00:00 2001 From: Alex Johnson Date: Sat, 19 Sep 2026 21:35:27 -0400 Subject: [PATCH 3/5] Log the request summary at DEBUG and the wire at TRACE Java's default root level is INFO and Spring Boot configures a console appender at it, so a per-request line at INFO is on in every application that never asked for one: a hundred requests, a hundred lines, no configuration. The reference SDKs put the summary at INFO, but a bare Python process has no handler on root and JS defaults its own level to warn, so INFO is off unless an application opts in. Sitting a tier lower reproduces that behaviour here. The wire moves to TRACE with it, which also separates 'show me the requests' from 'show me every body'. --- CHANGELOG.md | 2 +- README.md | 14 ++++---- .../github/premocloud/typesafe/Logging.java | 10 +++--- .../premocloud/typesafe/TypeSafeClient.java | 8 ++--- .../premocloud/typesafe/LoggingTest.java | 33 ++++++++++--------- 5 files changed, 34 insertions(+), 33 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index a0c3aaa..975854f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,7 +2,7 @@ ## Unreleased -- Logging through slf4j on the `io.github.premocloud.typesafe` logger: `INFO` for one line per request with status and elapsed, plus retries and connection failures; `DEBUG` for the wire in both directions. Credential headers are masked. Adds `org.slf4j:slf4j-api` (#6). +- Logging through slf4j on the `io.github.premocloud.typesafe` logger: `DEBUG` for one line per request with status and elapsed, plus retries and connection failures; `TRACE` for the wire in both directions. Nothing at `INFO` or above. Credential headers are masked. Adds `org.slf4j:slf4j-api` (#6). ## 0.3.0 - 2026-09-19 diff --git a/README.md b/README.md index 47a2535..69be0b7 100644 --- a/README.md +++ b/README.md @@ -181,9 +181,9 @@ logging environment is the application's job. | Level | What you get | | --- | --- | -| `INFO` | one line per request with its status and how long it took, plus a line per retry and per connection failure | -| `DEBUG` | the above, plus the wire in both directions: method, url, headers, body | -| `WARN` and above | nothing; failures are thrown, not logged | +| `DEBUG` | one line per request with its status and how long it took, plus a line per retry and per connection failure | +| `TRACE` | the above, plus the wire in both directions: method, url, headers, body | +| `INFO` and above | nothing, so a stock application sees none of this; failures are thrown, not logged | ```xml @@ -194,13 +194,13 @@ logging.level.io.github.premocloud.typesafe=DEBUG ``` ``` -DEBUG io.github.premocloud.typesafe - req-1 -> POST https://api.typesafe.ai/v1/systemone headers={Authorization=***, ...} body={"state":...} -INFO io.github.premocloud.typesafe - req-1 <- 200 in 214ms -DEBUG io.github.premocloud.typesafe - req-1 <- 200 headers={x-typesafe-request-id=req_01a0..., ...} body={"model":"jev-1.13.0",...} +TRACE io.github.premocloud.typesafe - req-1 -> POST https://api.typesafe.ai/v1/systemone headers={Authorization=***, ...} body={"state":...} +DEBUG io.github.premocloud.typesafe - req-1 <- 200 in 214ms +TRACE io.github.premocloud.typesafe - req-1 <- 200 headers={x-typesafe-request-id=req_01a0..., ...} body={"model":"jev-1.13.0",...} ``` Credential headers are masked, including any of your own containing `token` or `secret`. **Bodies are not masked**, so -`DEBUG` puts the state you are classifying into the log. +`TRACE` puts the state you are classifying into the log. ## Spring Boot diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java index 5def612..2947a7a 100644 --- a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java @@ -36,13 +36,13 @@ final class Logging { private Logging() { } - static void info(String format, Object... arguments) { - LOG.info(format, arguments); + static void request(String format, Object... arguments) { + LOG.debug(format, arguments); } - /** Guards the wire calls, so a redacted header string is never built when DEBUG is off. */ + /** Guards the wire calls, so a redacted header string is never built when TRACE is off. */ static boolean wireEnabled() { - return LOG.isDebugEnabled(); + return LOG.isTraceEnabled(); } /** @@ -51,7 +51,7 @@ static boolean wireEnabled() { * @param arrow {@code ->} for what was sent, {@code <-} for what came back */ static void wire(String tag, String arrow, String summary, HttpHeaders headers, @Nullable String body) { - LOG.debug("{} {} {} headers={} body={}", tag, arrow, summary, redact(headers), body == null ? "" : body); + LOG.trace("{} {} {} headers={} body={}", tag, arrow, summary, redact(headers), body == null ? "" : body); } /** diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java index 60cee6e..1433938 100644 --- a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java @@ -241,7 +241,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas Throwable cause = unwrap(error); if (cause instanceof HttpTimeoutException httpTimeout) { - Logging.info("{} timed out after {}ms", call.tag(), elapsedMs(startedNanos)); + Logging.request("{} timed out after {}ms", call.tag(), elapsedMs(startedNanos)); if (retryPolicy.retryTimeouts() && attempt < retryPolicy.maxRetries()) { return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); @@ -251,7 +251,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } if (cause instanceof IOException ioException) { - Logging.info("{} <- {} after {}ms", call.tag(), ioException.getClass().getSimpleName(), elapsedMs(startedNanos)); + Logging.request("{} <- {} after {}ms", call.tag(), ioException.getClass().getSimpleName(), elapsedMs(startedNanos)); if (retryPolicy.retryConnectionErrors() && attempt < retryPolicy.maxRetries()) { return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); @@ -264,7 +264,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } int status = response.statusCode(); - Logging.info("{} <- {} in {}ms", call.tag(), status, elapsedMs(startedNanos)); + Logging.request("{} <- {} in {}ms", call.tag(), status, elapsedMs(startedNanos)); if (Logging.wireEnabled()) { Logging.wire(call.tag(), "<-", String.valueOf(status), response.headers(), response.body()); @@ -276,7 +276,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas if (retryPolicy.retriesStatus(status) && attempt < retryPolicy.maxRetries()) { Duration delay = backoff(retryPolicy, attempt, retryPolicy.respectRetryAfter() ? RetryAfter.parse(response.headers()) : Optional.empty()); - Logging.info("{} retrying in {}ms (retry {}/{}) after {}", call.tag(), delay.toMillis(), + Logging.request("{} retrying in {}ms (retry {}/{}) after {}", call.tag(), delay.toMillis(), attempt + 1, retryPolicy.maxRetries(), status); return retryAsync(delay, template, type, timeout, retryPolicy, attempt + 1, call); diff --git a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java index 7f92ad7..c1ed6a1 100644 --- a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java +++ b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java @@ -43,7 +43,7 @@ void setUp() throws IOException { appender.setContext(context); appender.start(); logger.addAppender(appender); - logger.setLevel(Level.DEBUG); + logger.setLevel(Level.TRACE); // Capture only: without this the events also reach logback's default console appender and // every test run prints the request and response bodies. logger.setAdditive(false); @@ -58,27 +58,27 @@ void tearDown() { } @Test - void logsOneInfoLinePerRequestWithStatusAndElapsed() { + void logsOneDebugLinePerRequestWithStatusAndElapsed() { server.reply(200, RESPONSE_JSON); client().systemOne("state", Map.of("q", Noul.of("Yes?"))); - List info = messagesAt(Level.INFO); - assertEquals(1, info.size(), info.toString()); - assertTrue(info.get(0).matches(".*<- 200 in \\d+ms.*"), info.get(0)); + List debug = messagesAt(Level.DEBUG); + assertEquals(1, debug.size(), debug.toString()); + assertTrue(debug.get(0).matches(".*<- 200 in \\d+ms.*"), debug.get(0)); } @Test - void logsTheWireInBothDirectionsAtDebug() { + void logsTheWireInBothDirectionsAtTrace() { server.reply(200, RESPONSE_JSON); client().systemOne("state", Map.of("q", Noul.of("Yes?"))); - List debug = messagesAt(Level.DEBUG); - assertEquals(2, debug.size(), debug.toString()); - assertTrue(debug.get(0).contains("-> POST"), debug.get(0)); - assertTrue(debug.get(1).contains("<-"), debug.get(1)); - assertTrue(debug.get(1).contains("jev-1.13.0"), "response body is logged: " + debug.get(1)); + List trace = messagesAt(Level.TRACE); + assertEquals(2, trace.size(), trace.toString()); + assertTrue(trace.get(0).contains("-> POST"), trace.get(0)); + assertTrue(trace.get(1).contains("<-"), trace.get(1)); + assertTrue(trace.get(1).contains("jev-1.13.0"), "response body is logged: " + trace.get(1)); } @Test @@ -93,19 +93,20 @@ void neverLogsTheApiKey() { } @Test - void logsARetryLineAtInfo() { + void logsARetryLineAtDebug() { server.reply(429, "{}", Map.of("retry-after-ms", "1")); server.reply(200, RESPONSE_JSON); client().systemOne("state", Map.of("q", Noul.of("Yes?"))); - assertTrue(messagesAt(Level.INFO).stream().anyMatch(m -> m.contains("retrying in")), - messagesAt(Level.INFO).toString()); + assertTrue(messagesAt(Level.DEBUG).stream().anyMatch(m -> m.contains("retrying in")), + messagesAt(Level.DEBUG).toString()); } @Test - void logsNothingWhenTheLevelIsAboveInfo() { - logger.setLevel(Level.WARN); + void logsNothingAtTheDefaultSpringBootLevel() { + // Java's default root level is INFO, so a stock application must see nothing from this client. + logger.setLevel(Level.INFO); server.reply(200, RESPONSE_JSON); client().systemOne("state", Map.of("q", Noul.of("Yes?"))); From 596727852b5c2088834d842057cdb030c3136e38 Mon Sep 17 00:00:00 2001 From: Alex Johnson Date: Sat, 19 Sep 2026 22:05:03 -0400 Subject: [PATCH 4/5] Log directly through the slf4j logger; add request id to the summary line Drop Logging.request: call sites use LOG.debug so the level is visible where it is logged. Logging keeps wire() as the only redaction point. Fix the class doc, which still described the INFO/DEBUG tiers. --- README.md | 2 +- typesafe-sdk/build.gradle.kts | 1 - .../io/github/premocloud/typesafe/Logging.java | 16 ++++++---------- .../premocloud/typesafe/TypeSafeClient.java | 14 +++++++++----- .../github/premocloud/typesafe/LoggingTest.java | 2 +- 5 files changed, 17 insertions(+), 18 deletions(-) diff --git a/README.md b/README.md index 69be0b7..2414992 100644 --- a/README.md +++ b/README.md @@ -195,7 +195,7 @@ logging.level.io.github.premocloud.typesafe=DEBUG ``` TRACE io.github.premocloud.typesafe - req-1 -> POST https://api.typesafe.ai/v1/systemone headers={Authorization=***, ...} body={"state":...} -DEBUG io.github.premocloud.typesafe - req-1 <- 200 in 214ms +DEBUG io.github.premocloud.typesafe - req-1 <- 200 in 214ms (request req_01a0...) TRACE io.github.premocloud.typesafe - req-1 <- 200 headers={x-typesafe-request-id=req_01a0..., ...} body={"model":"jev-1.13.0",...} ``` diff --git a/typesafe-sdk/build.gradle.kts b/typesafe-sdk/build.gradle.kts index bb1a4ef..ee50943 100644 --- a/typesafe-sdk/build.gradle.kts +++ b/typesafe-sdk/build.gradle.kts @@ -20,4 +20,3 @@ mavenPublishing { description.set(project.description) } } - diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java index 2947a7a..5be400e 100644 --- a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/Logging.java @@ -13,21 +13,21 @@ /** * What the client logs, tiered as the official SDKs log it. * - *

{@code INFO} is one line per request with its status and how long it took, plus a line for each - * retry and each connection failure. {@code DEBUG} adds the wire in both directions: method, url, - * headers and body. Nothing is logged at {@code WARN} or above, because a failure is already thrown - * and the exception carries more than a log line would. + *

{@code DEBUG} is one line per request with its status, elapsed time and request id, plus a line + * for each retry and each connection failure. {@code TRACE} adds the wire in both directions: method, + * url, headers and body. Nothing is logged at {@code INFO} or above, because a failure is already + * thrown and the exception carries more than a log line would. * *

Set the level on the {@code io.github.premocloud.typesafe} logger, as for any library. There is * no environment variable: slf4j has no library-side level setting, and a library should let the * application configure its own logging. * - *

Credential headers are masked. Bodies are not, so {@code DEBUG} puts the state being classified + *

Credential headers are masked. Bodies are not, so {@code TRACE} puts the state being classified * into the log; both official SDKs document the same. */ final class Logging { - private static final Logger LOG = LoggerFactory.getLogger("io.github.premocloud.typesafe"); + static final Logger LOG = LoggerFactory.getLogger("io.github.premocloud.typesafe"); /** Masked in full. The union of what the official Python and JavaScript SDKs cover. */ private static final Set SECRET_HEADERS = Set.of( @@ -36,10 +36,6 @@ final class Logging { private Logging() { } - static void request(String format, Object... arguments) { - LOG.debug(format, arguments); - } - /** Guards the wire calls, so a redacted header string is never built when TRACE is off. */ static boolean wireEnabled() { return LOG.isTraceEnabled(); diff --git a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java index 1433938..ac9a4df 100644 --- a/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java +++ b/typesafe-sdk/src/main/java/io/github/premocloud/typesafe/TypeSafeClient.java @@ -5,6 +5,7 @@ import com.fasterxml.jackson.databind.JsonMappingException; import com.fasterxml.jackson.databind.ObjectMapper; import org.jspecify.annotations.Nullable; +import org.slf4j.Logger; import java.io.IOException; import java.net.URI; @@ -57,9 +58,11 @@ public final class TypeSafeClient { private static final String SDK_NAME = "typesafe-sdk"; private static final String VERSION = Objects.requireNonNullElse(TypeSafeClient.class.getPackage().getImplementationVersion(), "dev"); + private static final Logger LOG = Logging.LOG; + private static final AtomicLong REQUESTS = new AtomicLong(); + private final HttpClient httpClient; private final ObjectMapper objectMapper; - private static final AtomicLong REQUESTS = new AtomicLong(); private final String apiKey; private final String baseUrl; private final String defaultModel; @@ -241,7 +244,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas Throwable cause = unwrap(error); if (cause instanceof HttpTimeoutException httpTimeout) { - Logging.request("{} timed out after {}ms", call.tag(), elapsedMs(startedNanos)); + LOG.debug("{} timed out after {}ms", call.tag(), elapsedMs(startedNanos)); if (retryPolicy.retryTimeouts() && attempt < retryPolicy.maxRetries()) { return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); @@ -251,7 +254,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } if (cause instanceof IOException ioException) { - Logging.request("{} <- {} after {}ms", call.tag(), ioException.getClass().getSimpleName(), elapsedMs(startedNanos)); + LOG.debug("{} <- {} after {}ms", call.tag(), ioException.getClass().getSimpleName(), elapsedMs(startedNanos)); if (retryPolicy.retryConnectionErrors() && attempt < retryPolicy.maxRetries()) { return retryAsync(backoff(retryPolicy, attempt, Optional.empty()), template, type, timeout, retryPolicy, attempt + 1, call); @@ -264,7 +267,8 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas } int status = response.statusCode(); - Logging.request("{} <- {} in {}ms", call.tag(), status, elapsedMs(startedNanos)); + LOG.debug("{} <- {} in {}ms (request {})", call.tag(), status, elapsedMs(startedNanos), + response.headers().firstValue(TypeSafeApiException.REQUEST_ID_HEADER).orElse("-")); if (Logging.wireEnabled()) { Logging.wire(call.tag(), "<-", String.valueOf(status), response.headers(), response.body()); @@ -276,7 +280,7 @@ private CompletableFuture attemptAsync(HttpRequest.Builder template, Clas if (retryPolicy.retriesStatus(status) && attempt < retryPolicy.maxRetries()) { Duration delay = backoff(retryPolicy, attempt, retryPolicy.respectRetryAfter() ? RetryAfter.parse(response.headers()) : Optional.empty()); - Logging.request("{} retrying in {}ms (retry {}/{}) after {}", call.tag(), delay.toMillis(), + LOG.debug("{} retrying in {}ms (retry {}/{}) after {}", call.tag(), delay.toMillis(), attempt + 1, retryPolicy.maxRetries(), status); return retryAsync(delay, template, type, timeout, retryPolicy, attempt + 1, call); diff --git a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java index c1ed6a1..2c7490c 100644 --- a/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java +++ b/typesafe-sdk/src/test/java/io/github/premocloud/typesafe/LoggingTest.java @@ -65,7 +65,7 @@ void logsOneDebugLinePerRequestWithStatusAndElapsed() { List debug = messagesAt(Level.DEBUG); assertEquals(1, debug.size(), debug.toString()); - assertTrue(debug.get(0).matches(".*<- 200 in \\d+ms.*"), debug.get(0)); + assertTrue(debug.get(0).matches(".*<- 200 in \\d+ms \\(request .+\\).*"), debug.get(0)); } @Test From a51f60313225699b25739dca6fd697874df91fc9 Mon Sep 17 00:00:00 2001 From: Alex Johnson Date: Sat, 19 Sep 2026 22:20:40 -0400 Subject: [PATCH 5/5] Drop the dependency list from the README; the build file is the record --- README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/README.md b/README.md index 2414992..1a7e4d7 100644 --- a/README.md +++ b/README.md @@ -8,7 +8,7 @@ TypeSafe AI. It follows the conventions of the official [Python](https://github. [JavaScript](https://github.com/typesafe-ai/typesafe-sdk-js) SDKs so the three read alike. TypeSafe is a trademark of its owner; the name is used here only to describe what the library connects to. -Requires Java 17 or newer. Depends on Jackson and slf4j-api, plus JSpecify's nullness annotations. +Requires Java 17 or newer. ## Install