Skip to content

Eliminate unecessary allocations for suppressed logging levels - #5769

Open
solo (solonovamax) wants to merge 6 commits into
ktorio:release/3.xfrom
solonovamax:perf/logging-string-interpolation
Open

Eliminate unecessary allocations for suppressed logging levels#5769
solo (solonovamax) wants to merge 6 commits into
ktorio:release/3.xfrom
solonovamax:perf/logging-string-interpolation

Conversation

@solonovamax

Copy link
Copy Markdown
Contributor

Uses lazy logging functions in order to avoid unecessary allocations for logging levels that have been disabled (trace/debug)

There are no behavioural changes, other than that the allocations will be decreased.
The only other noticeable change is that in a couple of places a Throwable was used in the string interpolation. I changed this so that it passed the throwable as a parameter to the logging function, that way it will print the stack trace.

Also this fixes KTOR-9676 because the warning is wrong (and annoying), and since I'm already changing logging stuff, might as well do it here too.

Subsystem
A bunch:

  • client
    • client auth
    • client content negotiation
    • client core
  • server
    • server auth
    • server auth jwt
    • server call id
    • server call logging
    • server compression
    • server content negotiation
    • server core
    • server double receive
    • server partial content
    • server rate limit
    • server sessions
    • server sse
    • server status pages
    • server test base
    • server test suites
    • server websockets
  • utils
  • websockets

Motivation
I kept seeing log messages with string interpolation and it annoyed me.

Solution
Use the lazy logging functions for trace/debug to not perform the string interpolation.

@coderabbitai

coderabbitai Bot commented Jul 22, 2026

Copy link
Copy Markdown
Contributor

Review Change Stack

Note

Reviews paused

It looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the reviews.auto_review.auto_pause_after_reviewed_commits setting.

Use the following commands to manage reviews:

  • @coderabbitai resume to resume automatic reviews.
  • @coderabbitai review to trigger a single review.

Use the checkboxes below for quick actions:

  • ▶️ Resume reviews
  • 🔍 Trigger review
📝 Walkthrough

Walkthrough

Logging calls throughout Ktor now use lazy lambda-based trace and debug forms. Throwable-aware lazy overloads were added to the logging utilities, and client, server, shared, and test code was updated without changing functional control flow.

Changes

Lazy logging migration

Layer / File(s) Summary
Throwable-aware logging API
ktor-utils/common/src/io/ktor/util/logging/Logger.kt, ktor-utils/api/...
Adds lazy trace and debug overloads that accept a Throwable and evaluate messages only when enabled, with API metadata updated.
Client plugin logging
ktor-client/ktor-client-core/..., ktor-client/ktor-client-plugins/...
Converts client request, response, transformation, authentication, caching, cookie, lifecycle, retry, and content-negotiation logging to lazy forms.
Server core logging
ktor-server/ktor-server-core/...
Converts configuration, pipeline, reload, and plugin-installation logging to lazy forms.
Server plugin logging
ktor-server/ktor-server-plugins/...
Updates authentication, compression, content negotiation, sessions, status pages, partial content, SSE, WebSockets, call logging, and related plugin logging.
Test and shared logging
ktor-server/ktor-server-test-*/..., ktor-shared/ktor-websockets/...
Updates test lifecycle, compression/content test, call-logging test, and WebSocket ping-pong logging.

Estimated code review effort: 3 (Moderate) | ~25 minutes

Suggested labels: feature

Suggested reviewers: osipxd

🚥 Pre-merge checks | ✅ 4 | ❌ 1

❌ Failed checks (1 warning)

Check name Status Explanation Resolution
Docstring Coverage ⚠️ Warning Docstring coverage is 18.97% which is insufficient. The required threshold is 80.00%. Write docstrings for the functions missing them to satisfy the coverage threshold.
✅ Passed checks (4 passed)
Check name Status Explanation
Linked Issues check ✅ Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check ✅ Passed Check skipped because no linked issues were found for this pull request.
Title check ✅ Passed The title clearly reflects the main change: switching logging to lazy evaluation to reduce allocations.
Description check ✅ Passed The description covers Subsystem, Motivation, and Solution and even references KTOR-9676.
✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 3

🧹 Nitpick comments (1)
ktor-client/ktor-client-plugins/ktor-client-content-negotiation/common/src/io/ktor/client/plugins/contentnegotiation/ContentNegotiation.kt (1)

341-344: 🚀 Performance & Scalability | 🔵 Trivial | ⚡ Quick win

Use the lazy trace overload for the final conversion log.

The new isTraceEnabled guard still surrounds an eager LOGGER.trace("...") call. Use the same lazy form as the surrounding migration:

Proposed fix
-        if (LOGGER.isTraceEnabled && result !is ByteReadChannel) {
-            LOGGER.trace("Response body was converted to ${result::class} for $requestUrl.")
+        if (result !is ByteReadChannel) {
+            LOGGER.trace { "Response body was converted to ${result::class} for $requestUrl." }
         }

This keeps level gating in one place and aligns the remaining call with the lazy logging objective.

🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In
`@ktor-client/ktor-client-plugins/ktor-client-content-negotiation/common/src/io/ktor/client/plugins/contentnegotiation/ContentNegotiation.kt`
around lines 341 - 344, Update the final conversion log in the response
deserialization flow around suitableConverters.deserialize to use the logger’s
lazy trace overload, removing the explicit LOGGER.isTraceEnabled guard while
preserving the ByteReadChannel exclusion and existing message content.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Inline comments:
In
`@ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/cache/HttpCacheEntry.kt`:
- Around line 120-124: Update the request max-age parsing in HttpCacheEntry to
track whether a max-age directive was found separately from its numeric value.
Keep requestMaxAge equal to zero for absent or invalid values so existing
validation behavior is unchanged, but emit the LOGGER.trace message only when
the directive is actually absent and retain accurate wording for explicit
max-age=0.

In `@ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/UserAgent.kt`:
- Line 34: Update the trace message in the User-Agent header handling to
interpolate the configured value from pluginConfig.agent (the local agent
variable) instead of logging the literal text “agent”; preserve the existing
request URL context.

In
`@ktor-server/ktor-server-plugins/ktor-server-status-pages/common/src/io/ktor/server/plugins/statuspages/StatusPages.kt`:
- Around line 93-103: Update the three CallFailed trace statements in the
status-page handling flow around findHandlerByValue and handler execution to use
the throwable-aware LOGGER.trace(cause) overload, removing $cause from each
message while retaining the surrounding request URI, handler, and failure
context.

---

Nitpick comments:
In
`@ktor-client/ktor-client-plugins/ktor-client-content-negotiation/common/src/io/ktor/client/plugins/contentnegotiation/ContentNegotiation.kt`:
- Around line 341-344: Update the final conversion log in the response
deserialization flow around suitableConverters.deserialize to use the logger’s
lazy trace overload, removing the explicit LOGGER.isTraceEnabled guard while
preserving the ByteReadChannel exclusion and existing message content.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Pro

Run ID: 9276f260-536a-4f74-9222-72617e498ec6

📥 Commits

Reviewing files that changed from the base of the PR and between 8694912 and 57e60f2.

📒 Files selected for processing (42)
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/DefaultRequest.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/DefaultResponseValidation.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/DefaultTransform.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/HttpCallValidator.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/HttpPlainText.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/HttpRedirect.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/HttpRequestLifecycle.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/HttpRequestRetry.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/UserAgent.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/cache/HttpCacheEntry.kt
  • ktor-client/ktor-client-core/common/src/io/ktor/client/plugins/cookies/HttpCookies.kt
  • ktor-client/ktor-client-plugins/ktor-client-auth/common/src/io/ktor/client/plugins/auth/providers/BasicAuthProvider.kt
  • ktor-client/ktor-client-plugins/ktor-client-auth/common/src/io/ktor/client/plugins/auth/providers/BearerAuthProvider.kt
  • ktor-client/ktor-client-plugins/ktor-client-content-negotiation/common/src/io/ktor/client/plugins/contentnegotiation/ContentNegotiation.kt
  • ktor-server/ktor-server-core/common/src/io/ktor/server/application/ApplicationPlugin.kt
  • ktor-server/ktor-server-core/common/src/io/ktor/server/config/ConfigLoaders.kt
  • ktor-server/ktor-server-core/common/src/io/ktor/server/engine/DefaultEnginePipeline.kt
  • ktor-server/ktor-server-core/common/src/io/ktor/server/engine/DefaultTransform.kt
  • ktor-server/ktor-server-core/jvm/src/io/ktor/server/engine/EmbeddedServerJvm.kt
  • ktor-server/ktor-server-plugins/ktor-server-auth-jwt/jvm/src/io/ktor/server/auth/jwt/JWTAuth.kt
  • ktor-server/ktor-server-plugins/ktor-server-auth-jwt/jvm/src/io/ktor/server/auth/jwt/JWTUtils.kt
  • ktor-server/ktor-server-plugins/ktor-server-auth/common/src/io/ktor/server/auth/AuthenticationInterceptors.kt
  • ktor-server/ktor-server-plugins/ktor-server-auth/common/src/io/ktor/server/auth/OAuthProcedure.kt
  • ktor-server/ktor-server-plugins/ktor-server-call-id/common/src/io/ktor/server/plugins/callid/CallId.kt
  • ktor-server/ktor-server-plugins/ktor-server-call-logging/jvm/src/io/ktor/server/plugins/calllogging/CallLogging.kt
  • ktor-server/ktor-server-plugins/ktor-server-compression/jvm/src/io/ktor/server/plugins/compression/Compression.kt
  • ktor-server/ktor-server-plugins/ktor-server-content-negotiation/common/src/io/ktor/server/plugins/contentnegotiation/RequestConverter.kt
  • ktor-server/ktor-server-plugins/ktor-server-content-negotiation/common/src/io/ktor/server/plugins/contentnegotiation/ResponseConverter.kt
  • ktor-server/ktor-server-plugins/ktor-server-double-receive/common/src/io/ktor/server/plugins/doublereceive/DoubleReceive.kt
  • ktor-server/ktor-server-plugins/ktor-server-partial-content/common/src/io/ktor/server/plugins/partialcontent/PartialContent.kt
  • ktor-server/ktor-server-plugins/ktor-server-partial-content/common/src/io/ktor/server/plugins/partialcontent/PartialContentUtils.kt
  • ktor-server/ktor-server-plugins/ktor-server-rate-limit/common/src/io/ktor/server/plugins/ratelimit/RateLimitInterceptors.kt
  • ktor-server/ktor-server-plugins/ktor-server-sessions/common/src/io/ktor/server/sessions/SessionTrackerById.kt
  • ktor-server/ktor-server-plugins/ktor-server-sessions/common/src/io/ktor/server/sessions/SessionTrackerByValue.kt
  • ktor-server/ktor-server-plugins/ktor-server-sse/common/src/io/ktor/server/sse/SSEServerContent.kt
  • ktor-server/ktor-server-plugins/ktor-server-status-pages/common/src/io/ktor/server/plugins/statuspages/StatusPages.kt
  • ktor-server/ktor-server-plugins/ktor-server-websockets/common/src/io/ktor/server/websocket/Routing.kt
  • ktor-server/ktor-server-test-base/jvm/src/io/ktor/server/test/base/EngineTestBaseJvm.kt
  • ktor-server/ktor-server-test-suites/jvm/src/io/ktor/server/testing/suites/CompressionTestSuite.kt
  • ktor-server/ktor-server-test-suites/jvm/src/io/ktor/server/testing/suites/ContentTestSuite.kt
  • ktor-shared/ktor-websockets/common/src/io/ktor/websocket/PingPong.kt
  • ktor-utils/common/src/io/ktor/util/logging/Logger.kt

@solonovamax

Copy link
Copy Markdown
Contributor Author

It seems that CallLoggingTest failed. I'll address that in the morning.
There's also a couple of linting errors I'll address, and I also need to update the api dump.

@bjhham Bruce Hamilton (bjhham) left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks, I've been meaning to get around to these. Can you change the base to release/3.x so this can go into the next patch? You can use the ./switch-base-branch.sh for this.

@solonovamax

Copy link
Copy Markdown
Contributor Author

Thanks, I've been meaning to get around to these. Can you change the base to release/3.x so this can go into the next patch? You can use the ./switch-base-branch.sh for this.

sure, can do. I'll fix the test failure first though.

@coderabbitai coderabbitai Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🧹 Nitpick comments (1)
ktor-server/ktor-server-plugins/ktor-server-call-logging/jvm/test/io/ktor/server/plugins/calllogging/CallLoggingTest.kt (1)

514-514: 📐 Maintainability & Code Quality | 🔵 Trivial | ⚡ Quick win

Remove the unconditional debug print from the test.

This writes the collected messages to stdout on every run, including successful runs, creating noisy CI output. Keep this diagnostic local to failure investigation instead of committing it.

Proposed fix
-            println("messages:\n" + messages.joinToString(separator = ",\n", prefix = "[\n", postfix = "\n]") {"    \"$it\""})
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

In
`@ktor-server/ktor-server-plugins/ktor-server-call-logging/jvm/test/io/ktor/server/plugins/calllogging/CallLoggingTest.kt`
at line 514, Remove the unconditional println diagnostic that prints messages in
CallLoggingTest; retain the test assertions and behavior unchanged, without
adding replacement logging.
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.

Nitpick comments:
In
`@ktor-server/ktor-server-plugins/ktor-server-call-logging/jvm/test/io/ktor/server/plugins/calllogging/CallLoggingTest.kt`:
- Line 514: Remove the unconditional println diagnostic that prints messages in
CallLoggingTest; retain the test assertions and behavior unchanged, without
adding replacement logging.

ℹ️ Review info
⚙️ Run configuration

Configuration used: Path: .coderabbit.yaml

Review profile: CHILL

Plan: Pro Plus

Run ID: 9d53a23e-3797-497a-9885-19392ba4cb80

📥 Commits

Reviewing files that changed from the base of the PR and between 57e60f2 and ded0908.

📒 Files selected for processing (1)
  • ktor-server/ktor-server-plugins/ktor-server-call-logging/jvm/test/io/ktor/server/plugins/calllogging/CallLoggingTest.kt

@solonovamax
solo (solonovamax) force-pushed the perf/logging-string-interpolation branch from ded0908 to 293c31b Compare July 26, 2026 19:34
Uses lazy logging functions in order to avoid unecessary allocations
for logging levels that have been disabled (trace/debug)

Signed-off-by: solonovamax <solonovamax@12oclockpoint.com>
The warning is incorrect.

Signed-off-by: solonovamax <solonovamax@12oclockpoint.com>
Signed-off-by: solonovamax <solonovamax@12oclockpoint.com>
Signed-off-by: solonovamax <solonovamax@12oclockpoint.com>
Signed-off-by: solonovamax <solonovamax@12oclockpoint.com>
@solonovamax
solo (solonovamax) force-pushed the perf/logging-string-interpolation branch from e385e22 to 76d9ff1 Compare July 27, 2026 00:53
@solonovamax
solo (solonovamax) changed the base branch from main to release/3.x July 27, 2026 00:54
@solonovamax

Copy link
Copy Markdown
Contributor Author

It seems the failures are due to flaky tests.

@solonovamax

Copy link
Copy Markdown
Contributor Author

Because cd11882 (Aleksei Tirman (@Stexxe)) in release/3.x fixes KTOR-9676, I'm going to remove that change from this PR.

…-string-interpolation

# Conflicts:
#	ktor-server/ktor-server-plugins/ktor-server-compression/jvm/src/io/ktor/server/plugins/compression/Compression.kt
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants