diff --git a/.release-please-manifest.json b/.release-please-manifest.json index cb9d2541..7f3f5c84 100644 --- a/.release-please-manifest.json +++ b/.release-please-manifest.json @@ -1,3 +1,3 @@ { - ".": "0.22.0" + ".": "0.23.0" } \ No newline at end of file diff --git a/.stats.yml b/.stats.yml index c4ea5b74..1e4b924c 100644 --- a/.stats.yml +++ b/.stats.yml @@ -1,4 +1,4 @@ configured_endpoints: 40 -openapi_spec_url: https://storage.googleapis.com/stainless-sdk-openapi-specs/sent/sent-dm-7bb26574b68a4a83fda65dd095f3f54fc797d44988eb3ed8b72f6f1be768d284.yml -openapi_spec_hash: 92349dc439d33c6d4bd2a467a36a6190 +openapi_spec_url: https://storage.googleapis.com/stainless-sdk-openapi-specs/sent/sent-dm-21f3ad999906b6b886f79e15991d43f65bea811dec0a033e3cbe8730aec83f56.yml +openapi_spec_hash: 5b1e9de79d27d3ccd1ee2847f117be46 config_hash: 7fe4b7f38470a511342b783de698aa99 diff --git a/CHANGELOG.md b/CHANGELOG.md index 0819fd41..895186ba 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,13 @@ # Changelog +## 0.23.0 (2026-05-07) + +Full Changelog: [v0.22.0...v0.23.0](https://github.com/sentdm/sent-dm-java/compare/v0.22.0...v0.23.0) + +### Features + +* **client:** improve logging ([fcbd456](https://github.com/sentdm/sent-dm-java/commit/fcbd4563cbfd02d714a9dfe8fdbf991c4f10161b)) + ## 0.22.0 (2026-05-06) Full Changelog: [v0.21.0...v0.22.0](https://github.com/sentdm/sent-dm-java/compare/v0.21.0...v0.22.0) diff --git a/README.md b/README.md index f272d7ce..71614731 100644 --- a/README.md +++ b/README.md @@ -2,8 +2,8 @@ -[![Maven Central](https://img.shields.io/maven-central/v/dm.sent/sent-java)](https://central.sonatype.com/artifact/dm.sent/sent-java/0.22.0) -[![javadoc](https://javadoc.io/badge2/dm.sent/sent-java/0.22.0/javadoc.svg)](https://javadoc.io/doc/dm.sent/sent-java/0.22.0) +[![Maven Central](https://img.shields.io/maven-central/v/dm.sent/sent-java)](https://central.sonatype.com/artifact/dm.sent/sent-java/0.23.0) +[![javadoc](https://javadoc.io/badge2/dm.sent/sent-java/0.23.0/javadoc.svg)](https://javadoc.io/doc/dm.sent/sent-java/0.23.0) @@ -22,7 +22,7 @@ Use the Sent MCP Server to enable AI assistants to interact with this API, allow -The REST API documentation can be found on [docs.sent.dm](https://docs.sent.dm). Javadocs are available on [javadoc.io](https://javadoc.io/doc/dm.sent/sent-java/0.22.0). +The REST API documentation can be found on [docs.sent.dm](https://docs.sent.dm). Javadocs are available on [javadoc.io](https://javadoc.io/doc/dm.sent/sent-java/0.23.0). @@ -33,7 +33,7 @@ The REST API documentation can be found on [docs.sent.dm](https://docs.sent.dm). ### Gradle ```kotlin -implementation("dm.sent:sent-java:0.22.0") +implementation("dm.sent:sent-java:0.23.0") ``` ### Maven @@ -42,7 +42,7 @@ implementation("dm.sent:sent-java:0.22.0") dm.sent sent-java - 0.22.0 + 0.23.0 ``` @@ -294,8 +294,6 @@ The SDK throws custom unchecked exception types: ## Logging -The SDK uses the standard [OkHttp logging interceptor](https://github.com/square/okhttp/tree/master/okhttp-logging-interceptor). - Enable logging by setting the `SENT_LOG` environment variable to `info`: ```sh @@ -308,6 +306,19 @@ Or to `debug` for more verbose logging: export SENT_LOG=debug ``` +Or configure the client manually using the `logLevel` method: + +```java +import dm.sent.client.SentClient; +import dm.sent.client.okhttp.SentOkHttpClient; +import dm.sent.core.LogLevel; + +SentClient client = SentOkHttpClient.builder() + .fromEnv() + .logLevel(LogLevel.INFO) + .build(); +``` + ## ProGuard and R8 Although the SDK uses reflection, it is still usable with [ProGuard](https://github.com/Guardsquare/proguard) and [R8](https://developer.android.com/topic/performance/app-optimization/enable-app-optimization) because `sent-java-core` is published with a [configuration file](sent-java-core/src/main/resources/META-INF/proguard/sent-java-core.pro) containing [keep rules](https://www.guardsquare.com/manual/configuration/usage). diff --git a/build.gradle.kts b/build.gradle.kts index b34869e5..e66269b7 100644 --- a/build.gradle.kts +++ b/build.gradle.kts @@ -8,7 +8,7 @@ repositories { allprojects { group = "dm.sent" - version = "0.22.0" // x-release-please-version + version = "0.23.0" // x-release-please-version } subprojects { diff --git a/sent-java-client-okhttp/build.gradle.kts b/sent-java-client-okhttp/build.gradle.kts index dd99409f..5033550d 100644 --- a/sent-java-client-okhttp/build.gradle.kts +++ b/sent-java-client-okhttp/build.gradle.kts @@ -7,7 +7,6 @@ dependencies { api(project(":sent-java-core")) implementation("com.squareup.okhttp3:okhttp:4.12.0") - implementation("com.squareup.okhttp3:logging-interceptor:4.12.0") testImplementation(kotlin("test")) testImplementation("org.assertj:assertj-core:3.27.7") diff --git a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/OkHttpClient.kt b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/OkHttpClient.kt index 5110f815..7cc9c20f 100644 --- a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/OkHttpClient.kt +++ b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/OkHttpClient.kt @@ -35,7 +35,6 @@ import okhttp3.Request import okhttp3.RequestBody import okhttp3.RequestBody.Companion.toRequestBody import okhttp3.Response -import okhttp3.logging.HttpLoggingInterceptor import okio.BufferedSink import okio.buffer import okio.sink @@ -93,18 +92,6 @@ internal constructor(@JvmSynthetic internal val okHttpClient: okhttp3.OkHttpClie private fun newCall(request: HttpRequest, requestOptions: RequestOptions): Call { val clientBuilder = okHttpClient.newBuilder() - val logLevel = - when (System.getenv("SENT_LOG")?.lowercase()) { - "info" -> HttpLoggingInterceptor.Level.BASIC - "debug" -> HttpLoggingInterceptor.Level.BODY - else -> null - } - if (logLevel != null) { - clientBuilder.addNetworkInterceptor( - HttpLoggingInterceptor().setLevel(logLevel).apply { redactHeader("x-api-key") } - ) - } - requestOptions.timeout?.let { clientBuilder .connectTimeout(it.connect()) diff --git a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClient.kt b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClient.kt index 6b008c7a..a89de9b0 100644 --- a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClient.kt +++ b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClient.kt @@ -6,6 +6,7 @@ import com.fasterxml.jackson.databind.json.JsonMapper import dm.sent.client.SentClient import dm.sent.client.SentClientImpl import dm.sent.core.ClientOptions +import dm.sent.core.LogLevel import dm.sent.core.Sleeper import dm.sent.core.Timeout import dm.sent.core.http.Headers @@ -277,6 +278,15 @@ class SentOkHttpClient private constructor() { */ fun maxRetries(maxRetries: Int) = apply { clientOptions.maxRetries(maxRetries) } + /** + * The level at which to log request and response information. + * + * [fromEnv] will set the level from environment variables. See [LogLevel.fromEnv]. + * + * Defaults to [LogLevel.fromEnv]. + */ + fun logLevel(logLevel: LogLevel) = apply { clientOptions.logLevel(logLevel) } + /** * Customer API key for authentication. Use `sk_live_*` keys for production and `sk_test_*` * keys for sandbox/testing. Pass via the `x-api-key` header. diff --git a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClientAsync.kt b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClientAsync.kt index 9743ffb5..71b7dfa8 100644 --- a/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClientAsync.kt +++ b/sent-java-client-okhttp/src/main/kotlin/dm/sent/client/okhttp/SentOkHttpClientAsync.kt @@ -6,6 +6,7 @@ import com.fasterxml.jackson.databind.json.JsonMapper import dm.sent.client.SentClientAsync import dm.sent.client.SentClientAsyncImpl import dm.sent.core.ClientOptions +import dm.sent.core.LogLevel import dm.sent.core.Sleeper import dm.sent.core.Timeout import dm.sent.core.http.Headers @@ -277,6 +278,15 @@ class SentOkHttpClientAsync private constructor() { */ fun maxRetries(maxRetries: Int) = apply { clientOptions.maxRetries(maxRetries) } + /** + * The level at which to log request and response information. + * + * [fromEnv] will set the level from environment variables. See [LogLevel.fromEnv]. + * + * Defaults to [LogLevel.fromEnv]. + */ + fun logLevel(logLevel: LogLevel) = apply { clientOptions.logLevel(logLevel) } + /** * Customer API key for authentication. Use `sk_live_*` keys for production and `sk_test_*` * keys for sandbox/testing. Pass via the `x-api-key` header. diff --git a/sent-java-core/src/main/kotlin/dm/sent/core/ClientOptions.kt b/sent-java-core/src/main/kotlin/dm/sent/core/ClientOptions.kt index 5db51c44..572df77d 100644 --- a/sent-java-core/src/main/kotlin/dm/sent/core/ClientOptions.kt +++ b/sent-java-core/src/main/kotlin/dm/sent/core/ClientOptions.kt @@ -5,6 +5,7 @@ package dm.sent.core import com.fasterxml.jackson.databind.json.JsonMapper import dm.sent.core.http.Headers import dm.sent.core.http.HttpClient +import dm.sent.core.http.LoggingHttpClient import dm.sent.core.http.PhantomReachableClosingHttpClient import dm.sent.core.http.QueryParams import dm.sent.core.http.RetryingHttpClient @@ -96,6 +97,14 @@ private constructor( * Defaults to 2. */ @get:JvmName("maxRetries") val maxRetries: Int, + /** + * The level at which to log request and response information. + * + * [fromEnv] will set the level from environment variables. See [LogLevel.fromEnv]. + * + * Defaults to [LogLevel.fromEnv]. + */ + @get:JvmName("logLevel") val logLevel: LogLevel, /** * Customer API key for authentication. Use `sk_live_*` keys for production and `sk_test_*` keys * for sandbox/testing. Pass via the `x-api-key` header. @@ -155,6 +164,7 @@ private constructor( private var responseValidation: Boolean = false private var timeout: Timeout = Timeout.default() private var maxRetries: Int = 2 + private var logLevel: LogLevel = LogLevel.fromEnv() private var apiKey: String? = null @JvmSynthetic @@ -170,6 +180,7 @@ private constructor( responseValidation = clientOptions.responseValidation timeout = clientOptions.timeout maxRetries = clientOptions.maxRetries + logLevel = clientOptions.logLevel apiKey = clientOptions.apiKey } @@ -280,6 +291,15 @@ private constructor( */ fun maxRetries(maxRetries: Int) = apply { this.maxRetries = maxRetries } + /** + * The level at which to log request and response information. + * + * [fromEnv] will set the level from environment variables. See [LogLevel.fromEnv]. + * + * Defaults to [LogLevel.fromEnv]. + */ + fun logLevel(logLevel: LogLevel) = apply { this.logLevel = logLevel } + /** * Customer API key for authentication. Use `sk_live_*` keys for production and `sk_test_*` * keys for sandbox/testing. Pass via the `x-api-key` header. @@ -381,6 +401,7 @@ private constructor( * System properties take precedence over environment variables. */ fun fromEnv() = apply { + logLevel(LogLevel.fromEnv()) (System.getProperty("sent.baseUrl") ?: System.getenv("SENT_BASE_URL"))?.let { baseUrl(it) } @@ -437,7 +458,13 @@ private constructor( return ClientOptions( httpClient, RetryingHttpClient.builder() - .httpClient(httpClient) + .httpClient( + LoggingHttpClient.builder() + .httpClient(httpClient) + .clock(clock) + .level(logLevel) + .build() + ) .sleeper(sleeper) .clock(clock) .maxRetries(maxRetries) @@ -452,6 +479,7 @@ private constructor( responseValidation, timeout, maxRetries, + logLevel, apiKey, ) } diff --git a/sent-java-core/src/main/kotlin/dm/sent/core/LogLevel.kt b/sent-java-core/src/main/kotlin/dm/sent/core/LogLevel.kt new file mode 100644 index 00000000..ddd1b47b --- /dev/null +++ b/sent-java-core/src/main/kotlin/dm/sent/core/LogLevel.kt @@ -0,0 +1,33 @@ +// File generated from our OpenAPI spec by Stainless. + +package dm.sent.core + +/** The level at which to log request and response information. */ +enum class LogLevel { + /** No logging. */ + OFF, + /** Minimal request and response summary logs. No headers or bodies are logged. */ + INFO, + /** [INFO] logs plus details about request failures. */ + ERROR, + /** + * Full request and response logs. Sensitive headers are redacted, but sensitive data in request + * and response bodies may still be visible. + */ + DEBUG; + + /** Returns whether this level is at or higher than the given [level]. */ + fun shouldLog(level: LogLevel): Boolean = ordinal >= level.ordinal + + companion object { + + /** Returns a [LogLevel] based on the `SENT_LOG` environment variable. */ + fun fromEnv() = + when (System.getenv("SENT_LOG")?.lowercase()) { + "info" -> INFO + "error" -> ERROR + "debug" -> DEBUG + else -> OFF + } + } +} diff --git a/sent-java-core/src/main/kotlin/dm/sent/core/Utils.kt b/sent-java-core/src/main/kotlin/dm/sent/core/Utils.kt index b294d786..3df09b6b 100644 --- a/sent-java-core/src/main/kotlin/dm/sent/core/Utils.kt +++ b/sent-java-core/src/main/kotlin/dm/sent/core/Utils.kt @@ -5,6 +5,7 @@ package dm.sent.core import dm.sent.errors.SentInvalidDataException import java.util.Collections import java.util.SortedMap +import java.util.SortedSet import java.util.concurrent.CompletableFuture import java.util.concurrent.locks.Lock @@ -16,6 +17,11 @@ internal fun T?.getOrThrow(name: String): T = internal fun List.toImmutable(): List = if (isEmpty()) Collections.emptyList() else Collections.unmodifiableList(toList()) +@JvmSynthetic +internal fun > SortedSet.toImmutable(): SortedSet = + if (isEmpty()) Collections.emptySortedSet() + else Collections.unmodifiableSortedSet(toSortedSet(comparator() ?: Comparator.naturalOrder())) + @JvmSynthetic internal fun Map.toImmutable(): Map = if (isEmpty()) immutableEmptyMap() else Collections.unmodifiableMap(toMap()) diff --git a/sent-java-core/src/main/kotlin/dm/sent/core/http/LoggingHttpClient.kt b/sent-java-core/src/main/kotlin/dm/sent/core/http/LoggingHttpClient.kt new file mode 100644 index 00000000..3d36d6e1 --- /dev/null +++ b/sent-java-core/src/main/kotlin/dm/sent/core/http/LoggingHttpClient.kt @@ -0,0 +1,627 @@ +// File generated from our OpenAPI spec by Stainless. + +package dm.sent.core.http + +import dm.sent.core.LogLevel +import dm.sent.core.RequestOptions +import dm.sent.core.checkRequired +import dm.sent.core.toImmutable +import java.io.ByteArrayOutputStream +import java.io.InputStream +import java.io.OutputStream +import java.nio.ByteBuffer +import java.nio.charset.CharacterCodingException +import java.nio.charset.Charset +import java.nio.charset.CharsetDecoder +import java.nio.charset.CodingErrorAction +import java.nio.charset.StandardCharsets +import java.time.Clock +import java.time.Duration +import java.time.OffsetDateTime +import java.util.SortedSet +import java.util.concurrent.CompletableFuture +import java.util.concurrent.CompletionException +import kotlin.time.toKotlinDuration + +/** A wrapper [HttpClient] around [httpClient] that logs request and response information. */ +class LoggingHttpClient +private constructor( + /** The underlying [HttpClient] for making requests. */ + @get:JvmName("httpClient") val httpClient: HttpClient, + /** + * Sensitive headers to redact from logs. + * + * Defaults to `Set.of("x-api-key")`. + */ + @get:JvmName("redactedHeaders") val redactedHeaders: SortedSet, + /** + * The clock to use for measuring request and response durations. + * + * This is primarily useful for using a fake clock in tests. + * + * Defaults to [Clock.systemUTC]. + */ + @get:JvmName("clock") val clock: Clock, + /** + * The log level to use. + * + * Pass [LogLevel.fromEnv] to read from environment variables. + */ + @get:JvmName("level") val level: LogLevel, +) : HttpClient { + + override fun execute(request: HttpRequest, requestOptions: RequestOptions): HttpResponse { + val loggingRequest = logRequest(request) + + val before = OffsetDateTime.now(clock) + val response = + try { + httpClient.execute(loggingRequest, requestOptions) + } catch (e: Throwable) { + logFailure(e, Duration.between(before, OffsetDateTime.now(clock))) + throw e + } + + val took = Duration.between(before, OffsetDateTime.now(clock)) + return logResponse(response, took) + } + + override fun executeAsync( + request: HttpRequest, + requestOptions: RequestOptions, + ): CompletableFuture { + val loggingRequest = logRequest(request) + + val before = OffsetDateTime.now(clock) + val future = + try { + httpClient.executeAsync(loggingRequest, requestOptions) + } catch (e: Throwable) { + logFailure(e, Duration.between(before, OffsetDateTime.now(clock))) + throw e + } + return future.handle { response, error -> + val took = Duration.between(before, OffsetDateTime.now(clock)) + if (error != null) { + logFailure(unwrapCompletionException(error), took) + throw error + } + logResponse(response, took) + } + } + + private fun logRequest(request: HttpRequest): HttpRequest { + if (!level.shouldLog(LogLevel.INFO)) { + return request + } + + System.err.println( + buildString { + append("--> ${request.method} ${request.url()}") + request.body?.let { + val length = it.contentLength() + append(if (length >= 0) " ($length-byte body)" else " (unknown-length body)") + } + } + ) + + if (!level.shouldLog(LogLevel.DEBUG)) { + return request + } + + logHeaders(request.headers) + + if (request.body == null) { + System.err.println("--> END ${request.method}") + System.err.println() + return request + } + + return request + .toBuilder() + .body(LoggingHttpRequestBody(request.method, request.body)) + .build() + } + + private fun logResponse(response: HttpResponse, took: Duration): HttpResponse { + if (!level.shouldLog(LogLevel.INFO)) { + return response + } + + val contentLength = response.headers().values("Content-Length").firstOrNull()?.toIntOrNull() + System.err.println( + "<-- ${response.statusCode()} (${ + buildString { + append(took.format()) + contentLength?.let { append(", $contentLength-byte body") } + } + })" + ) + + if (!level.shouldLog(LogLevel.DEBUG)) { + return response + } + + logHeaders(response.headers()) + return LoggingHttpResponse(response) + } + + private fun logFailure(error: Throwable, took: Duration) { + if (!level.shouldLog(LogLevel.ERROR)) { + return + } + + System.err.println( + buildString { + append("<-- !! ${error.javaClass.simpleName}") + error.message?.let { append(": $it") } + append(" (${took.format()})") + } + ) + } + + private fun unwrapCompletionException(error: Throwable): Throwable = + if (error is CompletionException && error.cause != null) error.cause!! else error + + private fun logHeaders(headers: Headers) = + headers.names().forEach { name -> + headers.values(name).forEach { value -> + System.err.println("$name: ${if (redactedHeaders.contains(name)) "██" else value}") + } + } + + override fun close() = httpClient.close() + + fun toBuilder() = Builder().from(this) + + companion object { + + /** + * Returns a mutable builder for constructing an instance of [LoggingHttpClient]. + * + * The following fields are required: + * ```java + * .httpClient() + * .level() + * ``` + */ + @JvmStatic fun builder() = Builder() + } + + /** A builder for [LoggingHttpClient]. */ + class Builder internal constructor() { + + private var httpClient: HttpClient? = null + private var redactedHeaders: Set = setOf("x-api-key") + private var clock: Clock = Clock.systemUTC() + private var level: LogLevel? = null + + @JvmSynthetic + internal fun from(loggingHttpClient: LoggingHttpClient) = apply { + httpClient = loggingHttpClient.httpClient + redactedHeaders = loggingHttpClient.redactedHeaders + clock = loggingHttpClient.clock + level = loggingHttpClient.level + } + + /** The underlying [HttpClient] for making requests. */ + fun httpClient(httpClient: HttpClient) = apply { this.httpClient = httpClient } + + /** + * Sensitive headers to redact from logs. + * + * Defaults to `Set.of("x-api-key")`. + */ + fun redactedHeaders(redactedHeaders: Set) = apply { + this.redactedHeaders = redactedHeaders + } + + /** + * The clock to use for measuring request and response durations. + * + * This is primarily useful for using a fake clock in tests. + * + * Defaults to [Clock.systemUTC]. + */ + fun clock(clock: Clock) = apply { this.clock = clock } + + /** + * The log level to use. + * + * Pass [LogLevel.fromEnv] to read from environment variables. + */ + fun level(level: LogLevel) = apply { this.level = level } + + /** + * Returns an immutable instance of [LoggingHttpClient]. + * + * Further updates to this [Builder] will not mutate the returned instance. + * + * The following fields are required: + * ```java + * .httpClient() + * .level() + * ``` + * + * @throws IllegalStateException if any required field is unset. + */ + fun build(): LoggingHttpClient = + LoggingHttpClient( + checkRequired("httpClient", httpClient), + redactedHeaders.toSortedSet(String.CASE_INSENSITIVE_ORDER).toImmutable(), + clock, + checkRequired("level", level), + ) + } +} + +/** + * An [HttpRequestBody] wrapper that delegates to [body] while also logging line by line as it's + * written. + * + * The logging occurs in a streaming manner with minimal buffering. + */ +private class LoggingHttpRequestBody( + private val method: HttpMethod, + private val body: HttpRequestBody, +) : HttpRequestBody { + + private val charset by lazy { parseCharset(body.contentType()) } + + override fun writeTo(outputStream: OutputStream) { + val loggingOutputStream = LoggingOutputStream(outputStream, charset) + body.writeTo(loggingOutputStream) + + loggingOutputStream.flush() + System.err.println("--> END $method (${loggingOutputStream.writeCount()}-byte body)") + System.err.println() + } + + override fun contentType(): String? = body.contentType() + + override fun contentLength(): Long = body.contentLength() + + override fun repeatable(): Boolean = body.repeatable() + + override fun close() = body.close() +} + +/** + * An [OutputStream] wrapper that delegates to [outputStream] while also logging bytes line by line + * as it's written to. + * + * The written content is assumed to be in the given [charset] and the logging occurs in a streaming + * manner with minimal buffering. + */ +private class LoggingOutputStream(private val outputStream: OutputStream, charset: Charset?) : + OutputStream() { + + private val buffer = LoggingBuffer(charset) + + fun writeCount() = buffer.writeCount() + + override fun write(b: Int) { + outputStream.write(b) + buffer.write(b) + } + + override fun write(b: ByteArray, off: Int, len: Int) { + outputStream.write(b, off, len) + for (i in off until off + len) { + buffer.write(b[i].toInt() and 0xFF) + } + } + + /** Prints any currently buffered content. */ + override fun flush() { + buffer.flush() + outputStream.flush() + } + + override fun close() = outputStream.close() +} + +/** + * An [HttpResponse] wrapper that delegates to [response] while also logging line-by-line as it's + * read. + * + * The logging occurs in a streaming manner with minimal buffering. + */ +private class LoggingHttpResponse(private val response: HttpResponse) : HttpResponse { + + private val loggingBody: Lazy = lazy { + LoggingInputStream( + response.body(), + parseCharset(response.headers().values("Content-Type").firstOrNull()), + ) + } + + override fun statusCode(): Int = response.statusCode() + + override fun headers(): Headers = response.headers() + + override fun body(): InputStream = loggingBody.value + + override fun close() { + if (loggingBody.isInitialized()) { + loggingBody.value.close() + } + response.close() + } +} + +/** + * An [InputStream] wrapper that delegates to [inputStream] while also logging bytes line by line as + * it's read. + * + * The contents of [inputStream] are assumed to be in the given [charset] and the logging occurs in + * a streaming manner with minimal buffering. + */ +private class LoggingInputStream(private val inputStream: InputStream, charset: Charset?) : + InputStream() { + + private var isDone = false + private val buffer = LoggingBuffer(charset) + + override fun read(): Int { + if (isDone) { + return -1 + } + + val b = inputStream.read() + + if (b == -1) { + markDone() + return b + } + + buffer.write(b) + return b + } + + override fun read(b: ByteArray, off: Int, len: Int): Int { + if (isDone) { + return -1 + } + + val bytesRead = inputStream.read(b, off, len) + + if (bytesRead == -1) { + markDone() + return bytesRead + } + + for (i in off until off + bytesRead) { + buffer.write(b[i].toInt() and 0xFF) + } + return bytesRead + } + + override fun close() { + if (!isDone) { + markDone(closedEarly = true) + } + inputStream.close() + } + + private fun markDone(closedEarly: Boolean = false) { + isDone = true + buffer.flush() + val suffix = if (closedEarly) ", closed early" else "" + System.err.println("<-- END HTTP (${buffer.writeCount()}-byte body$suffix)") + System.err.println() + } +} + +/** + * A byte buffer that prints line by line, using the given [charset], as bytes are written to it. + * + * When [charset] is `null`, the buffer performs an upfront check to detect binary content. If + * non-whitespace ISO control characters are found in the first [PROBABLY_UTF8_CODE_POINT_LIMIT] + * code points, body logging is suppressed entirely. + */ +private class LoggingBuffer(charset: Charset?) { + + private val charset = charset ?: StandardCharsets.UTF_8 + + private val decoder: CharsetDecoder = + this.charset + .newDecoder() + .onMalformedInput(CodingErrorAction.REPORT) + .onUnmappableCharacter(CodingErrorAction.REPORT) + private var writeCount = 0 + private val buffer = ByteArrayOutputStream(128) + + /** + * Whether logging has been suppressed because the content doesn't appear to be readable text. + * + * This is only set when [charset] is `null` and the content fails the [isProbablyUtf8] check. + */ + private var suppressed = false + + /** + * Bytes accumulated for the [isProbablyUtf8] check before any lines are printed. + * + * Once the check passes (or [charset] is non-null), this is set to `null` and bytes flow + * directly to [buffer]. + */ + private var prefetchBuffer: ByteArrayOutputStream? = + if (charset != null) null else ByteArrayOutputStream(128) + + fun writeCount() = writeCount + + fun write(b: Int) { + if (writeCount == 0) { + // Print a newline before we start printing anything to separate the printed content + // from previous content. + System.err.println() + } + + writeCount++ + + if (suppressed) { + return + } + + val prefetch = prefetchBuffer + if (prefetch != null) { + prefetch.write(b) + // Continue accumulating until we have enough bytes to decide. + if (prefetch.size() < PROBABLY_UTF8_BYTE_LIMIT && b != '\n'.code) { + return + } + // We have enough bytes. Check if the content is probably UTF-8. + prefetchBuffer = null + val bytes = prefetch.toByteArray() + if (!isProbablyUtf8(bytes)) { + suppressed = true + System.err.println("(binary body omitted)") + return + } + // Content looks like UTF-8. Feed the accumulated bytes into the normal buffer. + for (byte in bytes) { + writeToBuffer(byte.toInt() and 0xFF) + } + return + } + + writeToBuffer(b) + } + + private fun writeToBuffer(b: Int) { + if (b == '\n'.code) { + flush() + return + } + + buffer.write(b) + } + + /** Prints any currently buffered content. */ + fun flush() { + if (suppressed) { + return + } + + // If we still have a prefetch buffer when flush is called (body was shorter than the + // limit), run the check now. + val prefetch = prefetchBuffer + if (prefetch != null) { + prefetchBuffer = null + val bytes = prefetch.toByteArray() + if (bytes.isEmpty()) { + return + } + if (!isProbablyUtf8(bytes)) { + suppressed = true + System.err.println("(binary body omitted)") + return + } + for (byte in bytes) { + writeToBuffer(byte.toInt() and 0xFF) + } + } + + if (buffer.size() == 0) { + return + } + + val line = + try { + decoder.decode(ByteBuffer.wrap(buffer.toByteArray())) + } catch (e: CharacterCodingException) { + "(omitted line is not valid $charset)" + } + buffer.reset() + System.err.println(line) + } +} + +/** The maximum number of code points to sample when checking if content is probably UTF-8. */ +private const val PROBABLY_UTF8_CODE_POINT_LIMIT = 64 + +/** + * The maximum number of bytes to accumulate before running the [isProbablyUtf8] check. UTF-8 code + * points are at most 4 bytes, so this accommodates [PROBABLY_UTF8_CODE_POINT_LIMIT] code points. + */ +private const val PROBABLY_UTF8_BYTE_LIMIT = PROBABLY_UTF8_CODE_POINT_LIMIT * 4 + +/** + * Returns `true` if the given [bytes] probably contain human-readable UTF-8 text. + * + * Decodes up to [PROBABLY_UTF8_CODE_POINT_LIMIT] code points and returns `false` if any + * non-whitespace ISO control characters are found, or if the bytes are not valid UTF-8. + */ +private fun isProbablyUtf8(bytes: ByteArray): Boolean { + try { + val decoder = + StandardCharsets.UTF_8.newDecoder() + .onMalformedInput(CodingErrorAction.REPORT) + .onUnmappableCharacter(CodingErrorAction.REPORT) + val charBuffer = decoder.decode(ByteBuffer.wrap(bytes)) + var codePointCount = 0 + var i = 0 + while (i < charBuffer.length && codePointCount < PROBABLY_UTF8_CODE_POINT_LIMIT) { + val codePoint = Character.codePointAt(charBuffer, i) + if (Character.isISOControl(codePoint) && !Character.isWhitespace(codePoint)) { + return false + } + i += Character.charCount(codePoint) + codePointCount++ + } + return true + } catch (e: CharacterCodingException) { + return false + } +} + +/** Returns the [Charset] in the given [contentType] string, or `null` if unspecified. */ +private fun parseCharset(contentType: String?): Charset? = + contentType + ?.split(";") + ?.drop(1) + ?.map { it.trim() } + ?.firstOrNull { it.startsWith("charset=", ignoreCase = true) } + ?.substringAfter("=") + ?.trim() + ?.removeSurrounding("\"") + ?.let { runCatching { charset(it) }.getOrNull() } + +/** Formats the [Duration] into a string like "1m 40s 467ms". */ +private fun Duration.format(): String = + toKotlinDuration().toComponents { days, hours, minutes, seconds, nanoseconds -> + buildString { + val milliseconds = nanoseconds / 1_000_000 + if (days > 0) { + append("${days}d") + } + if (hours > 0) { + if (isNotEmpty()) { + append(" ") + } + append("${hours}h") + } + if (minutes > 0) { + if (isNotEmpty()) { + append(" ") + } + append("${minutes}m") + } + if (seconds > 0) { + if (isNotEmpty()) { + append(" ") + } + append("${seconds}s") + } + if (milliseconds > 0) { + if (isNotEmpty()) { + append(" ") + } + append("${milliseconds}ms") + } + + if (isEmpty()) { + append("0s") + } + } + } diff --git a/sent-java-core/src/test/kotlin/dm/sent/core/http/LoggingHttpClientTest.kt b/sent-java-core/src/test/kotlin/dm/sent/core/http/LoggingHttpClientTest.kt new file mode 100644 index 00000000..d055216b --- /dev/null +++ b/sent-java-core/src/test/kotlin/dm/sent/core/http/LoggingHttpClientTest.kt @@ -0,0 +1,999 @@ +// File generated from our OpenAPI spec by Stainless. + +package dm.sent.core.http + +import dm.sent.core.LogLevel +import dm.sent.core.RequestOptions +import java.io.ByteArrayInputStream +import java.io.ByteArrayOutputStream +import java.io.IOException +import java.io.InputStream +import java.io.OutputStream +import java.io.PrintStream +import java.nio.charset.StandardCharsets +import java.time.Clock +import java.time.Instant +import java.time.ZoneOffset +import java.util.concurrent.CompletableFuture +import org.assertj.core.api.Assertions.assertThat +import org.assertj.core.api.Assertions.assertThatThrownBy +import org.junit.jupiter.api.AfterEach +import org.junit.jupiter.api.BeforeEach +import org.junit.jupiter.api.Test +import org.junit.jupiter.api.parallel.ResourceLock +import org.junit.jupiter.params.ParameterizedTest +import org.junit.jupiter.params.provider.ValueSource + +@ResourceLock("stderr") +internal class LoggingHttpClientTest { + + private lateinit var originalErr: PrintStream + private lateinit var errContent: ByteArrayOutputStream + + @BeforeEach + fun beforeEach() { + originalErr = System.err + errContent = ByteArrayOutputStream() + System.setErr(PrintStream(errContent)) + } + + @AfterEach + fun afterEach() { + System.setErr(originalErr) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun offLevel_noOutput(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.OFF) + + val response = client.execute(simpleGetRequest(), async).apply { body().readBytes() } + + assertThat(response.statusCode()).isEqualTo(200) + assertThat(stderrOutput()).isEmpty() + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_logsGetRequest(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.INFO) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- 200 (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_logsPostRequestWithBodySize(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.INFO) + + client.execute(postRequestWithBody("""{"key":"value"}"""), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> POST https://api.example.com/v1/resources (15-byte body) + |<-- 200 (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_logsRequestWithUnknownLengthBody(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.INFO) + + client + .execute(postRequestWithBody("""{"key":"value"}""", contentLength = -1L), async) + .body() + .readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> POST https://api.example.com/v1/resources (unknown-length body) + |<-- 200 (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_logsResponseStatusAndDuration(async: Boolean) { + val clock = + clockFrom( + Instant.parse("1998-04-21T00:00:00Z"), + Instant.parse("1998-04-21T00:00:01.234Z"), + ) + val client = loggingClient(fakeHttpClient(statusCode = 201), LogLevel.INFO, clock) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- 201 (1s 234ms) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_logsResponseContentLength(async: Boolean) { + val headers = + Headers.builder().put("Content-Length", "42").put("Content-Type", "text/plain").build() + val client = loggingClient(fakeHttpClient(responseHeaders = headers), LogLevel.INFO) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- 200 (0s, 42-byte body) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_doesNotLogHeaders(async: Boolean) { + val headers = Headers.builder().put("X-Custom", "visible").build() + val client = loggingClient(fakeHttpClient(responseHeaders = headers), LogLevel.INFO) + + client + .execute( + HttpRequest.builder() + .method(HttpMethod.GET) + .baseUrl("https://api.example.com") + .addPathSegment("v1") + .putHeader("X-Request-Custom", "req-value") + .build(), + async, + ) + .body() + .readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1 + |<-- 200 (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsGetWithEndMarker(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.DEBUG) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsRequestAndResponseHeaders(async: Boolean) { + val responseHeaders = + Headers.builder() + .put("X-Response-Id", "abc-123") + .put("Content-Type", "text/plain") + .build() + val client = + loggingClient(fakeHttpClient(responseHeaders = responseHeaders), LogLevel.DEBUG) + + client + .execute( + HttpRequest.builder() + .method(HttpMethod.GET) + .baseUrl("https://api.example.com") + .addPathSegment("test") + .putHeader("X-Custom", "my-value") + .build(), + async, + ) + .body() + .readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/test + |X-Custom: my-value + |--> END GET + | + |<-- 200 (0s) + |Content-Type: text/plain + |X-Response-Id: abc-123 + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_redactsSensitiveHeaders(async: Boolean) { + val client = + loggingClient( + fakeHttpClient(), + LogLevel.DEBUG, + redactedHeaders = setOf("Authorization", "X-Secret"), + ) + + client + .execute( + HttpRequest.builder() + .method(HttpMethod.GET) + .baseUrl("https://api.example.com") + .addPathSegment("test") + .putHeader("Authorization", "Bearer token-123") + .putHeader("X-Secret", "secret-value") + .putHeader("X-Public", "public-value") + .build(), + async, + ) + .body() + .readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/test + |Authorization: ██ + |X-Public: public-value + |X-Secret: ██ + |--> END GET + | + |<-- 200 (0s) + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_redactsHeadersCaseInsensitively(async: Boolean) { + val client = + loggingClient( + fakeHttpClient(), + LogLevel.DEBUG, + redactedHeaders = setOf("Authorization"), + ) + + client + .execute( + HttpRequest.builder() + .method(HttpMethod.GET) + .baseUrl("https://api.example.com") + .addPathSegment("test") + .putHeader("authorization", "Bearer secret") + .build(), + async, + ) + .body() + .readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/test + |authorization: ██ + |--> END GET + | + |<-- 200 (0s) + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsRequestBody(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.DEBUG) + val body = """{"name":"test","value":42}""" + + client.execute(postRequestWithBody(body), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> POST https://api.example.com/v1/resources (26-byte body) + | + |{"name":"test","value":42} + |--> END POST (26-byte body) + | + |<-- 200 (0s) + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsResponseBody(async: Boolean) { + val responseBody = """{"id":1,"status":"ok"}""" + val headers = Headers.builder().put("Content-Type", "application/json").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + val response = client.execute(simpleGetRequest(), async) + val body = response.body().readBytes().toString(StandardCharsets.UTF_8) + + assertThat(body).isEqualTo(responseBody) + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: application/json + | + |{"id":1,"status":"ok"} + |<-- END HTTP (22-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsBinaryResponseBodyAsOmitted(async: Boolean) { + val binaryBody = ByteArray(256) { it.toByte() } + val client = loggingClient(fakeHttpClient(responseBody = binaryBody), LogLevel.DEBUG) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + | + |(binary body omitted) + |<-- END HTTP (256-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsMultilineResponseBody(async: Boolean) { + val multilineBody = "line1\nline2\nline3" + val headers = Headers.builder().put("Content-Type", "text/plain; charset=utf-8").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = multilineBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: text/plain; charset=utf-8 + | + |line1 + |line2 + |line3 + |<-- END HTTP (17-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsResponseBodyWithExplicitCharset(async: Boolean) { + val responseBody = "héllo wörld" + val headers = Headers.builder().put("Content-Type", "text/plain; charset=utf-8").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: text/plain; charset=utf-8 + | + |héllo wörld + |<-- END HTTP (13-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsResponseBodyWithNoContentType(async: Boolean) { + val responseBody = "plain text body" + val client = + loggingClient( + fakeHttpClient(responseBody = responseBody.toByteArray(StandardCharsets.UTF_8)), + LogLevel.DEBUG, + ) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + | + |plain text body + |<-- END HTTP (15-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsEmptyResponseBody(async: Boolean) { + val client = loggingClient(fakeHttpClient(), LogLevel.DEBUG) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |<-- END HTTP (0-byte body) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsEndHttpMarkerOnEarlyClose(async: Boolean) { + val responseBody = """{"id":1,"status":"ok"}""" + val headers = Headers.builder().put("Content-Type", "application/json").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + val body = client.execute(simpleGetRequest(), async).body() + body.read(ByteArray(5)) + body.close() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: application/json + | + |{"id" + |<-- END HTTP (5-byte body, closed early) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsEndHttpMarkerOnCloseWithoutReading(async: Boolean) { + val responseBody = """{"id":1,"status":"ok"}""" + val headers = Headers.builder().put("Content-Type", "application/json").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + client.execute(simpleGetRequest(), async).body().close() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: application/json + |<-- END HTTP (0-byte body, closed early) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsEndHttpMarkerWhenResponseClosedAfterPartialRead(async: Boolean) { + val responseBody = """{"id":1,"status":"ok"}""" + val headers = Headers.builder().put("Content-Type", "application/json").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + val response = client.execute(simpleGetRequest(), async) + response.body().read(ByteArray(5)) + response.close() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: application/json + | + |{"id" + |<-- END HTTP (5-byte body, closed early) + | + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_doesNotLogEndHttpMarkerWhenResponseClosedWithoutBodyAccess(async: Boolean) { + val responseBody = """{"id":1,"status":"ok"}""" + val headers = Headers.builder().put("Content-Type", "application/json").build() + val client = + loggingClient( + fakeHttpClient( + responseHeaders = headers, + responseBody = responseBody.toByteArray(StandardCharsets.UTF_8), + ), + LogLevel.DEBUG, + ) + + client.execute(simpleGetRequest(), async).close() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- 200 (0s) + |Content-Type: application/json + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun errorLevel_logsRequestFailure(async: Boolean) { + val clock = + clockFrom( + Instant.parse("1998-04-21T00:00:00Z"), + Instant.parse("1998-04-21T00:00:01.234Z"), + ) + val client = + loggingClient( + failingHttpClient(IOException("Connection refused")), + LogLevel.ERROR, + clock, + ) + + assertThatThrownBy { client.execute(simpleGetRequest(), async) } + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- !! IOException: Connection refused (1s 234ms) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun infoLevel_doesNotLogRequestFailure(async: Boolean) { + val client = + loggingClient(failingHttpClient(IOException("Connection refused")), LogLevel.INFO) + + assertThatThrownBy { client.execute(simpleGetRequest(), async) } + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun debugLevel_logsRequestFailureAfterHeaders(async: Boolean) { + val client = + loggingClient(failingHttpClient(IOException("Connection refused")), LogLevel.DEBUG) + + assertThatThrownBy { client.execute(simpleGetRequest(), async) } + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |--> END GET + | + |<-- !! IOException: Connection refused (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun errorLevel_logsRequestFailureWithoutMessage(async: Boolean) { + val client = loggingClient(failingHttpClient(IOException()), LogLevel.ERROR) + + assertThatThrownBy { client.execute(simpleGetRequest(), async) } + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- !! IOException (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun offLevel_doesNotLogRequestFailure(async: Boolean) { + val client = + loggingClient(failingHttpClient(IOException("Connection refused")), LogLevel.OFF) + + assertThatThrownBy { client.execute(simpleGetRequest(), async) } + + assertThat(stderrOutput()).isEmpty() + } + + @Test + fun errorLevel_logsExecuteAsyncSynchronousThrow() { + val error = IOException("Connection refused") + val client = + loggingClient( + object : HttpClient { + override fun execute( + request: HttpRequest, + requestOptions: RequestOptions, + ): HttpResponse = throw UnsupportedOperationException() + + override fun executeAsync( + request: HttpRequest, + requestOptions: RequestOptions, + ): CompletableFuture = throw error + + override fun close() {} + }, + LogLevel.ERROR, + ) + + assertThatThrownBy { client.execute(simpleGetRequest(), async = true) }.isSameAs(error) + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- !! IOException: Connection refused (0s) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun durationFormat_seconds(async: Boolean) { + val clock = + clockFrom( + Instant.parse("1998-04-21T00:00:00Z"), + Instant.parse("1998-04-21T00:00:02.500Z"), + ) + val client = loggingClient(fakeHttpClient(), LogLevel.INFO, clock) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- 200 (2s 500ms) + |""" + .trimMargin() + ) + } + + @ParameterizedTest + @ValueSource(booleans = [false, true]) + fun durationFormat_minutesAndSeconds(async: Boolean) { + val clock = + clockFrom( + Instant.parse("1998-04-21T00:00:00Z"), + Instant.parse("1998-04-21T00:01:40.467Z"), + ) + val client = loggingClient(fakeHttpClient(), LogLevel.INFO, clock) + + client.execute(simpleGetRequest(), async).body().readBytes() + + assertThat(stderrOutput()) + .isEqualTo( + """ + |--> GET https://api.example.com/v1/resources + |<-- 200 (1m 40s 467ms) + |""" + .trimMargin() + ) + } + + @Test + fun builder_toBuilder_roundtrips() { + val delegate = fakeHttpClient() + val clock = Clock.fixed(Instant.parse("1998-04-21T00:00:00Z"), ZoneOffset.UTC) + val client = + LoggingHttpClient.builder() + .httpClient(delegate) + .level(LogLevel.DEBUG) + .redactedHeaders(setOf("X-Secret")) + .clock(clock) + .build() + + val rebuilt = client.toBuilder().build() + + assertThat(rebuilt.httpClient).isSameAs(delegate) + assertThat(rebuilt.level).isEqualTo(LogLevel.DEBUG) + assertThat(rebuilt.redactedHeaders).containsExactly("X-Secret") + assertThat(rebuilt.clock).isEqualTo(clock) + } + + @Test + fun close_delegatesToUnderlyingClient() { + var closed = false + val delegate = + object : HttpClient { + override fun execute( + request: HttpRequest, + requestOptions: RequestOptions, + ): HttpResponse = throw UnsupportedOperationException() + + override fun executeAsync( + request: HttpRequest, + requestOptions: RequestOptions, + ): CompletableFuture = throw UnsupportedOperationException() + + override fun close() { + closed = true + } + } + val client = loggingClient(delegate, LogLevel.OFF) + + client.close() + + assertThat(closed).isTrue() + } + + private fun stderrOutput(): String = errContent.toString("UTF-8") + + private fun loggingClient( + httpClient: HttpClient, + level: LogLevel, + clock: Clock = clockFrom(Instant.parse("1998-04-21T00:00:00Z")), + redactedHeaders: Set = setOf("x-api-key"), + ): LoggingHttpClient = + LoggingHttpClient.builder() + .httpClient(httpClient) + .level(level) + .clock(clock) + .redactedHeaders(redactedHeaders) + .build() + + private fun simpleGetRequest(): HttpRequest = + HttpRequest.builder() + .method(HttpMethod.GET) + .baseUrl("https://api.example.com") + .addPathSegment("v1") + .addPathSegment("resources") + .build() + + private fun postRequestWithBody( + body: String, + contentType: String = "application/json", + contentLength: Long? = null, + ): HttpRequest = + HttpRequest.builder() + .method(HttpMethod.POST) + .baseUrl("https://api.example.com") + .addPathSegment("v1") + .addPathSegment("resources") + .body( + object : HttpRequestBody { + private val bytes = body.toByteArray(StandardCharsets.UTF_8) + + override fun writeTo(outputStream: OutputStream) { + outputStream.write(bytes) + } + + override fun contentType(): String = contentType + + override fun contentLength(): Long = contentLength ?: bytes.size.toLong() + + override fun repeatable(): Boolean = true + + override fun close() {} + } + ) + .build() + + private fun fakeHttpClient( + statusCode: Int = 200, + responseHeaders: Headers = Headers.builder().build(), + responseBody: ByteArray = ByteArray(0), + ): HttpClient = + object : HttpClient { + override fun execute( + request: HttpRequest, + requestOptions: RequestOptions, + ): HttpResponse { + // Consume the request body if present to trigger logging. + request.body?.let { + val out = ByteArrayOutputStream() + it.writeTo(out) + } + return fakeResponse(statusCode, responseHeaders, responseBody) + } + + override fun executeAsync( + request: HttpRequest, + requestOptions: RequestOptions, + ): CompletableFuture = + CompletableFuture.completedFuture(execute(request, requestOptions)) + + override fun close() {} + } + + private fun failingHttpClient(error: Throwable): HttpClient = + object : HttpClient { + override fun execute( + request: HttpRequest, + requestOptions: RequestOptions, + ): HttpResponse { + request.body?.let { + val out = ByteArrayOutputStream() + it.writeTo(out) + } + throw error + } + + override fun executeAsync( + request: HttpRequest, + requestOptions: RequestOptions, + ): CompletableFuture { + val future = CompletableFuture() + future.completeExceptionally(error) + return future + } + + override fun close() {} + } + + private fun fakeResponse(statusCode: Int, headers: Headers, body: ByteArray): HttpResponse = + object : HttpResponse { + override fun statusCode(): Int = statusCode + + override fun headers(): Headers = headers + + override fun body(): InputStream = ByteArrayInputStream(body) + + override fun close() {} + } + + private fun clockFrom(vararg instants: Instant): Clock = + object : Clock() { + private var index = 0 + + override fun getZone() = ZoneOffset.UTC + + override fun withZone(zone: java.time.ZoneId?) = this + + override fun instant(): Instant { + val instant = instants[index % instants.size] + index++ + return instant + } + } + + private fun HttpClient.execute(request: HttpRequest, async: Boolean): HttpResponse = + if (async) executeAsync(request).get() else execute(request) +}