Log prefix updates for CASSJAVA-97 (request traceability) #3

absurdfarce · 2025-09-05T20:17:05Z

This PR represents a proposal to update the implementation of log prefix in the current PR for CASSJAVA-97. Specifically I'm aiming to address two distinct goals:

The user may configure a session name in the HOCON config; this config should be respected throughout generated log prefixes
The generated request ID exists at the CqlRequestHandler level and it should continue to be represented at this level. The current implementation replaces the "session|handler hash code" in it's entirety with the generated request ID.

… distinct entity (which keeps support for session names configured in the config) and (2) makes the request ID scoped by CqlRequestHandler.

absurdfarce · 2025-09-05T20:19:22Z

The current impl appears to work (in very limited testing). Using this code and this config:

datastax-java-driver {
  basic.load-balancing-policy {
    local-datacenter: datacenter1
  }
  advanced.request-id {
    generator {
      class = W3CContextRequestIdGenerator
    }
  }
}

I'm getting log messages such as the following:

646  [main] TRACE com.datastax.oss.driver.internal.core.cql.CqlRequestHandler  - [s0|e2c995e287e6b78f60f94cff2b4fb290] Creating new handler for request com.datastax.oss.driver.internal.core.cql.DefaultSimpleS
tatement@1418bc1a                                                                                                                                                                                          	 
649  [main] TRACE com.datastax.oss.driver.internal.core.loadbalancing.DefaultLoadBalancingPolicy  - [s0|default] Prioritizing 0 local replicas
651  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.channel.InFlightHandler  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Writing s0|00-e2c995e287e6b78f60f94cff2b4fb290-899681c9cfc8a3d
4-00|0 on stream id 0                                                                                                                                                                                      	 
651  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.protocol.ByteBufSegmentBuilder  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Added frame 0 to current self-contained segment (bringi
ng it to 148/131071 bytes, 1 frames)                                                               	 
651  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.protocol.ByteBufSegmentBuilder  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Flushing last self-contained segment (148/131071 bytes,
 1 frames)                                                                                         	 
652  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.cql.CqlRequestHandler  - [s0|00-e2c995e287e6b78f60f94cff2b4fb290-899681c9cfc8a3d4-00|0] Request sent on [id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.
0.0.1:9042]      	 
657  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.protocol.SegmentToFrameDecoder  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Decoded response frame 0 from self-contained segment
657  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.protocol.SegmentToFrameDecoder  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Done processing self-contained segment (1 frames)
658  [s0-io-3] DEBUG com.datastax.oss.driver.internal.core.channel.InFlightHandler  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Got last response on in-flight stream id 0, completing and rel
easing
658  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.channel.InFlightHandler  - [s0|id: 0x40a3ffa5, L:/127.0.0.1:39768 - R:/127.0.0.1:9042] Releasing stream id 0
658  [s0-io-3] TRACE com.datastax.oss.driver.internal.core.cql.CqlRequestHandler  - [s0|00-e2c995e287e6b78f60f94cff2b4fb290-899681c9cfc8a3d4-00|0] Got result, completing

I want to try a few other changes to see if I can clean up the API a bit but hopefully this conveys the general idea.

absurdfarce · 2025-09-08T04:06:48Z

Bah, API changes didn't exactly work out. I thought there might be some way to cleanly create a LogPrefix object which encapsulated the policies around log prefixes within a given space... but that doesn't come out as cleanly as one might like.

Going with this for now... we can revise in the future if need be.

absurdfarce · 2025-09-08T04:17:41Z

Oh, and while we're on the topic of future things... it prolly makes sense to move away from log prefixes like we're using now and towards a purer notion of something like structured logging. The Go folks certainly seem to like it and this "session ID|handler ID|execution count?" usage is doing something very similar already (albeit with a custom format). There's already some notion of support for this in logback, although we may have to flesh it out a bit.

absurdfarce · 2025-09-08T04:20:15Z

Oh, and for the record... my local "request-traceability" branch corresponds to the branch used to create the PR at this commit.

lukasz-antoniak · 2025-09-09T14:00:21Z

Can we make both methods of RequestIdGenerator contain Request as a parameter? I think interface would be more consistent.

SiyaoIsHiding · 2025-09-09T09:12:34Z

core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestIdGenerator.java

   */
-  String getNodeRequestId(
-      @NonNull Request statement, @NonNull String sessionRequestId, int executionCount);
+  String getRequestId(@NonNull Request statement, @NonNull String parentId);


Why do we want to use the term "parent ID" and "request ID"?

apache#2037
Bret agreed to keep consistent with C# driver

But Bret wants getSessionId and getNodeId, and preferably getRequestId and getMessageId.

I think getSessionId and getNodeId will be very confusing because users will expect sessionid as the name of the CqlSession, like s0, and nodeId as the host ID.

Re: getRequestId and getMessageId, they won't be consistent with our RequestTracker interface, e.g. onError and onNodeError.

I think sessionRequestId and nodeRequestId are still largely consistent with onError and onNodeError than requestId and messageId

SiyaoIsHiding · 2025-09-09T15:50:32Z

core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestIdGenerator.java

   */
-  String getNodeRequestId(
-      @NonNull Request statement, @NonNull String sessionRequestId, int executionCount);
+  String getRequestId(@NonNull Request statement, @NonNull String parentId);


apache#2037
Bret agreed to keep consistent with C# driver

SiyaoIsHiding · 2025-09-09T16:06:09Z

core/src/main/java/com/datastax/oss/driver/internal/core/cql/CqlRequestHandler.java

-            : sessionLogPrefix + "|" + this.hashCode();
-    LOG.trace("[{}] Creating new handler for request {}", logPrefix, statement);
+    this.sessionName = sessionName;
+    this.sessionId =


sessionId will be confusing because it sounds like the id of the session (e.g. s0) instead of the id of the request. Maybe sessionRequestId

SiyaoIsHiding · 2025-09-09T16:14:18Z

core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestIdGenerator.java

   */
-  String getNodeRequestId(
-      @NonNull Request statement, @NonNull String sessionRequestId, int executionCount);
+  String getRequestId(@NonNull Request statement, @NonNull String parentId);


But Bret wants getSessionId and getNodeId, and preferably getRequestId and getMessageId.

SiyaoIsHiding · 2025-09-09T16:23:24Z

core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestIdGenerator.java

   */
-  String getNodeRequestId(
-      @NonNull Request statement, @NonNull String sessionRequestId, int executionCount);
+  String getRequestId(@NonNull Request statement, @NonNull String parentId);


I think getSessionId and getNodeId will be very confusing because users will expect sessionid as the name of the CqlSession, like s0, and nodeId as the host ID.

Re: getRequestId and getMessageId, they won't be consistent with our RequestTracker interface, e.g. onError and onNodeError.

I think sessionRequestId and nodeRequestId are still largely consistent with onError and onNodeError than requestId and messageId

absurdfarce · 2025-09-09T17:11:11Z

@SiyaoIsHiding and I talked about this pretty extensively in a meeting today. Our plan going forward is to merge this PR into @SiyaoIsHiding 's PR for CASSJAVA-97 and pick up the naming conversation(s) there. I definitely want to keep questions around naming consolidated in one place and this PR isn't ideal for that. The primary point for this PR was to demonstrate that log prefix and request ID aren't the same thing and that we need to keep the logic for each separate. That goal seems to be accomplished (and seems to be relatively uncontroversial) so the simplest path forward was to get that change in and then move on to any questions around params/naming.

absurdfarce · 2025-09-10T20:47:02Z

This PR has now been merged into the main PR for CASSJAVA-97. We'll continue any outstanding discussions on that PR.

Implement new log prefix formatting which (1) preserves session ID as…

c8435f5

… distinct entity (which keeps support for session names configured in the config) and (2) makes the request ID scoped by CqlRequestHandler.

absurdfarce mentioned this pull request Sep 8, 2025

CASSJAVA-97: Let users inject an ID for each request and write to the custom payload apache/cassandra-java-driver#2037

Merged

SiyaoIsHiding reviewed Sep 9, 2025

View reviewed changes

absurdfarce closed this Sep 10, 2025

Log prefix updates for CASSJAVA-97 (request traceability) #3

Log prefix updates for CASSJAVA-97 (request traceability) #3

Uh oh!

Conversation

absurdfarce commented Sep 5, 2025

Uh oh!

absurdfarce commented Sep 5, 2025

Uh oh!

absurdfarce commented Sep 8, 2025

Uh oh!

absurdfarce commented Sep 8, 2025

Uh oh!

absurdfarce commented Sep 8, 2025

Uh oh!

lukasz-antoniak commented Sep 9, 2025

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

absurdfarce commented Sep 9, 2025

Uh oh!

absurdfarce commented Sep 10, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants