diff --git a/ktor-client/ktor-client-plugins/ktor-client-logging/common/src/io/ktor/client/plugins/logging/Logging.kt b/ktor-client/ktor-client-plugins/ktor-client-logging/common/src/io/ktor/client/plugins/logging/Logging.kt index b49742a3e0..d4ef1bbcdb 100644 --- a/ktor-client/ktor-client-plugins/ktor-client-logging/common/src/io/ktor/client/plugins/logging/Logging.kt +++ b/ktor-client/ktor-client-plugins/ktor-client-logging/common/src/io/ktor/client/plugins/logging/Logging.kt @@ -87,6 +87,10 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", fun shouldBeLogged(request: HttpRequestBuilder): Boolean = filters.isEmpty() || filters.any { it(request) } + fun isNone(): Boolean = level == LogLevel.NONE + fun isInfo(): Boolean = level == LogLevel.INFO + fun isHeaders(): Boolean = level == LogLevel.HEADERS + fun isBody(): Boolean = level == LogLevel.BODY suspend fun logOutgoingContent(content: OutgoingContent, process: (ByteReadChannel) -> ByteReadChannel = { it }): Pair { return when(content) { @@ -126,7 +130,7 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", } suspend fun logRequestStdFormat(request: HttpRequestBuilder) { - if (level == LogLevel.NONE) return + if (isNone()) return val uri = URLBuilder().takeFrom(request.url).build().pathQuery() val body = request.body @@ -145,11 +149,11 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", val contentLength = headers[HttpHeaders.ContentLength]?.toLongOrNull() val startLine = when { (request.method == HttpMethod.Get) - || ((level.headers || level.body) && contentLength != null) - || (level.headers && contentLength == null) + || ((isHeaders() || isBody()) && contentLength != null) + || (isHeaders() && contentLength == null) || headers.contains(HttpHeaders.ContentEncoding) -> "--> ${request.method.value} $uri" - level.info && contentLength != null -> "--> ${request.method.value} $uri ($contentLength-byte body)" + isInfo() && contentLength != null -> "--> ${request.method.value} $uri ($contentLength-byte body)" body is OutgoingContent.WriteChannelContent || body is OutgoingContent.ReadChannelContent -> "--> ${request.method.value} $uri (unknown-byte body)" @@ -170,7 +174,7 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", logger.log("$name: ${values.joinToString(separator = ", ")}") } - if (level != LogLevel.BODY || request.method == HttpMethod.Get) { + if (!isBody() || request.method == HttpMethod.Get) { logger.log("--> END ${request.method.value}") return } @@ -197,24 +201,27 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", } suspend fun logResponseStdFormat(response: HttpResponse): HttpResponse { - if (level == LogLevel.NONE) return response + if (isNone()) return response var contentLength = response.headers[HttpHeaders.ContentLength]?.toLongOrNull() val request = response.request val duration = response.responseTime.timestamp - response.requestTime.timestamp val startLine = when { - level == LogLevel.BODY || (level == LogLevel.HEADERS && contentLength != null) + response.headers[HttpHeaders.TransferEncoding] == "chunked" + && (isInfo() || isHeaders()) -> "<-- ${response.status} ${request.url.pathQuery()} (${duration}ms, unknown-byte body)" + + isBody() || (isInfo() && contentLength == null) || (isHeaders() && contentLength != null) || (response.headers[HttpHeaders.ContentEncoding] == "gzip") -> "<-- ${response.status} ${request.url.pathQuery()} (${duration}ms)" - level.info && contentLength != null -> "<-- ${response.status} ${request.url.pathQuery()} (${duration}ms, $contentLength-byte body)" + isInfo() && contentLength != null -> "<-- ${response.status} ${request.url.pathQuery()} (${duration}ms, $contentLength-byte body)" else -> "<-- ${response.status} ${request.url.pathQuery()} (${duration}ms, unknown-byte body)" } logger.log(startLine) - if (!level.headers && level != LogLevel.BODY) { + if (!isHeaders() && !isBody()) { return response } @@ -222,7 +229,7 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", logger.log("$name: ${values.joinToString(separator = ", ")}") } - if (!level.body) { + if (!isBody()) { logger.log("<-- END HTTP") return response } @@ -234,8 +241,9 @@ public val Logging: ClientPlugin = createClientPlugin("Logging", val (origChannel, newChannel) = response.rawContent.split(response) logger.log("") - logger.log(newChannel.readRemaining().readText()) - logger.log("<-- END HTTP") + val text = newChannel.readRemaining().readText() + logger.log(text) + logger.log("<-- END HTTP (${duration}ms, ${text.length}-byte body)") return object : HttpResponse() { override val call: HttpClientCall diff --git a/ktor-client/ktor-client-plugins/ktor-client-logging/jvm/test/io/ktor/client/plugins/logging/NewFormatTest.kt b/ktor-client/ktor-client-plugins/ktor-client-logging/jvm/test/io/ktor/client/plugins/logging/NewFormatTest.kt index e1e3684d56..329c37506f 100644 --- a/ktor-client/ktor-client-plugins/ktor-client-logging/jvm/test/io/ktor/client/plugins/logging/NewFormatTest.kt +++ b/ktor-client/ktor-client-plugins/ktor-client-logging/jvm/test/io/ktor/client/plugins/logging/NewFormatTest.kt @@ -247,7 +247,7 @@ class NewFormatTest { } @Test - fun basicPostWithGzip() = runTest { + fun basicGzippedBodyContentEncoding() = runTest { HttpClient(MockEngine) { install(Logging) { level = LogLevel.INFO @@ -261,14 +261,16 @@ class NewFormatTest { val channel = GZipEncoder.encode(ByteReadChannel("a".repeat(1024))) respond(channel, headers = Headers.build { append(HttpHeaders.ContentEncoding, "gzip") + append(HttpHeaders.ContentLength, "29") }) } } }.use { client -> - client.post("/") + val response = client.get("/") + assertEquals("a".repeat(1024), response.bodyAsText()) - log.assertLogEqual("--> POST / (0-byte body)") - .assertLogMatch(Regex("""<-- 200 OK / \(\d+ms, unknown-byte body\)""")) + log.assertLogEqual("--> GET /") + .assertLogMatch(Regex("""<-- 200 OK / \(\d+ms\)""")) .assertNoMoreLogs() } } @@ -388,7 +390,7 @@ class NewFormatTest { } @Test - fun headersPostWithGzip() = runTest { + fun headersGzippedResponseBodyContentEncoding() = runTest { HttpClient(MockEngine) { install(Logging) { level = LogLevel.HEADERS @@ -538,12 +540,12 @@ class NewFormatTest { .assertLogEqual("Content-Type: text/plain") .assertLogEqual("") .assertLogEqual("hello!") - .assertLogEqual("<-- END HTTP") + .assertLogMatch(Regex("""<-- END HTTP \(\d+ms, 6-byte body\)""")) .assertNoMoreLogs() } @Test - fun bodyChunkedResponseBody() = testWithLevel(LogLevel.BODY, handle = { respondChunked(ByteReadChannel("hello!")) }) { client -> + fun bodyResponseBodyChunked() = testWithLevel(LogLevel.BODY, handle = { respondChunked(ByteReadChannel("hello!")) }) { client -> client.get("/") log.assertLogEqual("--> GET /") .assertLogEqual("Accept-Charset: UTF-8") @@ -554,7 +556,7 @@ class NewFormatTest { .assertLogEqual("Content-Type: text/plain") .assertLogEqual("") .assertLogEqual("hello!") - .assertLogEqual("<-- END HTTP") + .assertLogMatch(Regex("""<-- END HTTP \(\d+ms, 6-byte body\)""")) .assertNoMoreLogs() }