-
Notifications
You must be signed in to change notification settings - Fork 885
Add ExecutionInfo to RequestTracker methods #1640
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: 4.x
Are you sure you want to change the base?
Conversation
Thanks for the PR @ajweave! Have you signed the Contributor License Agreement for contributions to DataStax open source projects? If not you can find it at https://cla.datastax.com/. Thanks! |
@ajweave Just so I have this straight in my own head, here's how I understand the relationship between this PR and the ask on JAVA-3046. This PR clearly extends the callbacks for request success and failure to include the extra ExecutionInfo object while JAVA-3046 asks for new callbacks all together for the start of a request. Do I have the contours basically right there? |
@absurdfarce the current behavior of RequestTracker providing success/failure after the fact is sufficient for my needs. The only additional thing I require is the ExecutionInfo. Making RequestTracker support finer-grained lifecycle events is ok with me as long as I can get my hands on ExecutionInfo in onSuccess. |
@absurdfarce I've signed the CLA. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looks pretty good! Want to make sure we don't miss onNodeError() here but otherwise this appears to be ready to go.
@NonNull String requestLogPrefix, | ||
@NonNull ExecutionInfo executionInfo) { | ||
// delegate call to the old method | ||
onNodeSuccess(request, latencyNanos, executionProfile, node, requestLogPrefix); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Looks like onSuccess(), onError() and onNodeSuccess() are updated here. We should probably update onNodeError() as well in order to keep the API internally consistent. I don't know that it's actually used in existing driver code beyond MultiplexingRequestTracker but it's still a good idea to keep the API internally consistent.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
IIRC, from what I could tell, in most error cases no ExecutionInfo is present (but I'm still new to the driver code). I've started going through it again and I think CqlRequestHandler can be refactored to pass it in for some cases. I'll add the new arg without the NonNull annotation.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
CqlRequestHandler is a bit tangled - there's a NodeResponseCallback inner class with a trackNodeError method and on the containing class, there's a setFinalError method where the ExecutionInfo is created.
Ideally, setFinalError could call RequestTracker.setNodeError with the ExecutionInfo, but that's already being done in NodeResponseCallback.trackNodeError so I'm thinking it's appropriate to move the trackNodeError method to the containing class.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I agree that CqlRequestHandler does get a little tangled; async code certainly will do that if you don't keep an eye on it :).
My comment wasn't connected to the current implementation of CqlRequestHandler, though. Individual request handlers are created by the various request processors. These processors vary widely in implementation, and that's just for the ones we've written; they're defined by an interface so users are always free to write their own! With that in mind I'd say it's important to think about RequestTracker as a general interface which may (or may not) be used by any given handler for any given processor.
With that in mind, I'd argue it's important for RequestTracker to present a coherent interface that's consistent across all the on*() handler methods unless there's a very good reason to diverge. There doesn't appear to be any such reason in this case, thus my recommendation to update onNodeError() to keep things consistent.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I totally agree on keeping the interface consistent.
I've been going through the handlers and for the most part, calls to onNodeError with a null ExecutionInfo are feasible, so that's a good first step. Should a larger refactoring effort to route the ExecutionInfo to those methods be postponed? I suppose a good argument against the refactoring work is that the node-level events in the interface can be considered "in-progress" requests and the final ExecutionInfo instance will be delivered in onSuccess.
The only place I see where we can't honor the NonNull contract for onSuccess without significant changes is ContinuousRequestHandlerBase.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I figured out a solution in ContinuousRequestHandlerBase
.
https://github.com/datastax/java-driver/pull/1640/files#r1247216557
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can we do this in CqlRequestHandler.NodeResponseCallback.trackNodeError
?
private void trackNodeError(Node node, Throwable error, long nodeResponseTimeNanos) {
if (requestTracker instanceof NoopRequestTracker) {
return;
}
if (nodeResponseTimeNanos == NANOTIME_NOT_MEASURED_YET) {
nodeResponseTimeNanos = System.nanoTime();
}
long latencyNanos = nodeResponseTimeNanos - this.nodeStartTimeNanos;
ExecutionInfo executionInfo =
new DefaultExecutionInfo(
statement,
node,
startedSpeculativeExecutionsCount.get(),
execution,
errors,
null,
null,
true,
session,
context,
executionProfile);
requestTracker.onNodeError(
statement, error, latencyNanos, executionProfile, node, logPrefix, executionInfo);
}
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I also explored how to pass in ExecutionInfo from ContinuousRequestHandlerBase, see here. How do you think of this approach?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Changes to ContinuousRequestHandlerBase
merged. Thank you.
.../src/main/java/com/datastax/oss/driver/internal/core/tracker/MultiplexingRequestTracker.java
Show resolved
Hide resolved
core/src/main/java/com/datastax/oss/driver/internal/core/tracker/NoopRequestTracker.java
Outdated
Show resolved
Hide resolved
core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestTracker.java
Show resolved
Hide resolved
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There are a few places in the code and tests which are still calling the now deprecated methods which could result in callbacks being missed for those who override the new methods (happy to discuss if there was a good reason for that, and if so consider adding a comment above those invocations and interface methods) and a few quibbles about annotation inconsistency.
core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestTracker.java
Show resolved
Hide resolved
core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestTracker.java
Show resolved
Hide resolved
core/src/main/java/com/datastax/oss/driver/api/core/tracker/RequestTracker.java
Show resolved
Hide resolved
@@ -94,9 +98,12 @@ public void onError( | |||
long latencyNanos, | |||
@NonNull DriverExecutionProfile executionProfile, | |||
@Nullable Node node, | |||
@NonNull String logPrefix) { | |||
@NonNull String logPrefix, | |||
@NonNull ExecutionInfo executionInfo) { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Here executionInfo
is marked @NonNull
but RequestTracker#onError
does not have that annotation (arguably it should be @Nullable
since it looks like CqlRequestHandler
may pass it as null
)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yes, should be @nullable, fixed.
@@ -51,7 +53,8 @@ public void onError( | |||
long latencyNanos, | |||
@NonNull DriverExecutionProfile executionProfile, | |||
Node node, | |||
@NonNull String requestPrefix) { | |||
@NonNull String requestPrefix, | |||
@NonNull ExecutionInfo executionInfo) { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Similar to with MultiplexingRequestTracker
, this is not marked @NonNull
in the interface
core/src/main/java/com/datastax/oss/driver/internal/core/tracker/RequestLogger.java
Outdated
Show resolved
Hide resolved
session, | ||
context, | ||
executionProfile)); | ||
executionInfo = |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
is there a reason we only build and pass along the executionInfo
for DriverException
errors?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
For reasons unknown to me, the existing code was only creating a new ExecutionInfo
for DriverErrors
. I suppose this is because DriverException
has a setter for it. Now I suppose we have another use for the ExecutionInfo
so I can change it to create one for all Throwables
.
session, | ||
context, | ||
executionProfile); | ||
this.executionInfo = |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Added an instance variable here for the ExecutionInfo
. It gets populated and later passed to the RequestTracker
in completeResultSetFuture
.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not sure this will always work correctly - the executionInfo
field on the NodeResponseCallback
is populated when the response is processed in processResultResponse
, but before being used when firing the request tracker methods in completeResultSetFuture
, responses may be queued. If another request comes in before the earlier response is removed from the queue the executionInfo
field will be overwritten. When the earlier response is later removed from the queue, the execution info provided to the request tracker could be the one from the newer request.
Instead of a field attached to the NodeResponseCallback
, perhaps you could use the execution info stored on the resultSet
object in processResultResponse
? - it's a shame there isn't a common interface (perhaps a useful improvement to file for another time) but it looks like both ContinuousAsyncResultSet
and AsyncGraphResultSet
have getters for ExecutionInfo objects.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
On further thought, since you only have an Object
at this stage, I don't know how you would get an execution info for the request tracker call if you end up with a something that isn't a ContinuousAsyncResultSet
or AsyncGraphResultSet
so perhaps the solution I suggested above isn't going to work.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I apologize for calling out details you no doubt already know off the top of your head, it's just for my own benefit being new to the code.
This is a bit of a pickle. ResultSetT
is just an Object
and it looks like just sharpening up the definition of that type parameter is impossible because there's not a unified type structure for the different kinds of results in the internal API.
I could add a type check and cast for both AsyncPagingIterable
and AsyncGraphResultSet
which both provide a getExecutionInfo
method.
If that works, then we might want to go a bit further and refactor a bit to add a marking interface or something to prevent other types from being passed in, but that seems like an extensive change.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I removed the ExecutionInfo
instance variable and added type checks and casts for both AsyncPagingIterable
and AsyncGraphResultSet
to get the ExecutionInfo
from there.
I attempted to run the ContinuousPagingIT
test with DSE to validate, but I'm having trouble with CCM. The CCM node fails to start with this error:
Cannot start node if snitch's data center (dc1) differs from previous data center (Cassandra)
I'm setting these Java options:
-Dccm.dse=true -Dccm.version=6.8.38
Any tips for running the integration test locally are appreciated.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It's a bit of work to set up. I ran all the tests against this branch, and it passed all the tests.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks for addressing the earlier feedback! I have some concerns about the way you're saving the executionInfo
in the continous request handler, and one more potential clash between @NonNull
and @Nullable
but otherwise looks good to me!
[edit]
[ERROR] Failed to execute goal com.coveo:fmt-maven-plugin:2.9:check (default) on project java-driver-integration-tests: Found 1 non-complying files, failing build -> [Help 1]
Oh and can you run the coveo format plugin before your next push? Travis CI is complaining about some formatting issues with this changeset
core/src/main/java/com/datastax/oss/driver/internal/core/tracker/RequestLogger.java
Outdated
Show resolved
Hide resolved
session, | ||
context, | ||
executionProfile); | ||
this.executionInfo = |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm not sure this will always work correctly - the executionInfo
field on the NodeResponseCallback
is populated when the response is processed in processResultResponse
, but before being used when firing the request tracker methods in completeResultSetFuture
, responses may be queued. If another request comes in before the earlier response is removed from the queue the executionInfo
field will be overwritten. When the earlier response is later removed from the queue, the execution info provided to the request tracker could be the one from the newer request.
Instead of a field attached to the NodeResponseCallback
, perhaps you could use the execution info stored on the resultSet
object in processResultResponse
? - it's a shame there isn't a common interface (perhaps a useful improvement to file for another time) but it looks like both ContinuousAsyncResultSet
and AsyncGraphResultSet
have getters for ExecutionInfo objects.
…equestTracker methods")
Now that the donation to Apache is complete, I'd like to move forward with this change. @hhughes , @absurdfarce , please take a look. |
@hhughes , @absurdfarce , gentle reminder to review these changes. |
+1 , this would be a great addition , allowing more granular access to execution metrics. |
Ping @SiyaoIsHiding for (hopefully) another review |
May you please merge apache/4.x to your branch? |
Sorry for the delay. I will get this done tomorrow. I appreciate the attention here. |
@NonNull String requestLogPrefix) { | ||
// If client doesn't override onSuccess with requestLogPrefix delegate call to the old method | ||
onSuccess(request, latencyNanos, executionProfile, node); | ||
@NonNull String requestLogPrefix, |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Small request: would it be possible to keep the log prefix as the last parameter? This has been kind of a tacit convention so far.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Refactored to make requestLogPrefix the last arg in all the methods.
Good work @ajweave, sorry to keep you waiting. Two things to consider from my end. Feel free to disagree since both are more of coding style category. In request handlers (e.g.
Both methods create their own instance of All of this can be done, because we decide to construct
I was even thinking of changing the three Edit:
|
A quick status update here: there's some overlap between the changes in this PR and some changes being proposed in @chibenwa's PR to minimize the number of resolutions of ExecutionProfile in CqlRequestHandler. Since that PR is quite a bit smaller and simpler I'd like to get it in first and then rebase this PR against those changes; doing it the other way around seems like a lot more work :). I've mentioned this relationship to the other committers on ASF Slack so hopefully we can get the other PR in quickly... we'll see how that goes. |
@NonNull String requestLogPrefix) { | ||
// If client doesn't override onSuccess with requestLogPrefix delegate call to the old method | ||
onSuccess(request, latencyNanos, executionProfile, node); | ||
// If client doesn't override onSuccess with executionInfo delegate call to the old method |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@lukasz-antoniak and I thought we don't need the parameter request
, executionProfile
, and node
here, because they are all contained in executionInfo
object. So we can change it to:
default void onSuccess(
long latencyNanos,
@NonNull ExecutionInfo executionInfo,
@NonNull String requestLogPrefix) {
onSuccess(executionInfo.getRequest(), latencyNanos, executionInfo.getExecutionProfile(), executionInfo.getCoordinator(), requestLogPrefix);
}
If we leave it like it is, the user may be confused if the ones in the parameters and the ones in exeuctionInfo
Object are not consistent.
@absurdfarce @adutra How do you think?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Good point. As long as we retain and deprecate the old method signatures for backwards-compatability, I'm good.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
agreed, I like the concise method signature as well!
Seeing onSuccess(long latencyNanos, @NonNull ExecutionInfo executionInfo, @NonNull String requestLogPrefix)
makes me wonder why we couldn't just put latency on ExecutionInfo
? That seems like it could be useful for those consuming ExecutionInfo
on their result set.
I think it's fine as proposed though 👍
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
We may consider putting requestLogPrefix
into ExecutionInfo
, too.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Just adding my support for the change, being as there are a few outstanding things (including getting #1623 merged in and this method signature discussion), I'll wait before formally +1ing but eager to give my +1 when it is all set 👍 .
@NonNull String requestLogPrefix) { | ||
// If client doesn't override onSuccess with requestLogPrefix delegate call to the old method | ||
onSuccess(request, latencyNanos, executionProfile, node); | ||
// If client doesn't override onSuccess with executionInfo delegate call to the old method |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
agreed, I like the concise method signature as well!
Seeing onSuccess(long latencyNanos, @NonNull ExecutionInfo executionInfo, @NonNull String requestLogPrefix)
makes me wonder why we couldn't just put latency on ExecutionInfo
? That seems like it could be useful for those consuming ExecutionInfo
on their result set.
I think it's fine as proposed though 👍
We realize that |
@ajweave, @tolbertam, I have tried to solve my comments and submitted PR to Andrew's fork: ajweave#1. Could you please review the changes and comment? I am not enforcing any of those, just trying cleanup already existing code a little. |
Thank you for pitching in. I will take a look. |
RequestTracker implementations may want to use the ExecutionInfo object e.g logging request/response size, etc.