MINOR: Include response in request log #3801
Conversation
|
@rajinisivaram, maybe you can review this. cc @theduderog |
|
retest this please |
| val apiThrottleTimeMs = nanosToMs(responseCompleteTimeNanos - apiRemoteCompleteTimeNanos) | ||
| val responseQueueTimeMs = nanosToMs(responseDequeueTimeNanos - responseCompleteTimeNanos) | ||
| val responseSendTimeMs = nanosToMs(endTimeNanos - responseDequeueTimeNanos) | ||
| val totalTimeMs = nanosToMs(endTimeNanos - startTimeNanos) |
There was a problem hiding this comment.
+1 on naming these with units
|
|
||
| val builder = new StringBuilder(256) | ||
| builder.append("Completed request:").append(requestDesc(detailsEnabled)) | ||
| .append(",response:").append(response.responseAsString.getOrElse("")) |
There was a problem hiding this comment.
A little annoying that we need the getOrElse since responseAsString should be defined. Also, do we need a detailed option for responses as well?
There was a problem hiding this comment.
Right although not sure how to avoid the getOrElse. We could fail instead of falling back the empty string though. Would that be better? Originally when I did this there were cases where it could be None, but that's no longer the case as you pointed out.
I thought we could do the detailed response thing separately since it's only useful if we change the response classes to take advantage of it. What do you think?
There was a problem hiding this comment.
I changed it to throw an exception since it should not happen.
|
Thanks, @ijuma |
|
|
||
| val builder = new StringBuilder(256) | ||
| builder.append("Completed request:").append(requestDesc(detailsEnabled)) | ||
| .append(",response:").append(response.responseAsString.getOrElse("")) |
There was a problem hiding this comment.
A little annoying that we need the getOrElse since responseAsString should be defined. Also, do we need a detailed option for responses as well?
| class Response(val request: Request, val responseSend: Option[Send], val responseAction: ResponseAction) { | ||
| /** responseAsString should only be defined if request logging is enabled */ | ||
| class Response(val request: Request, val responseSend: Option[Send], val responseAction: ResponseAction, | ||
| val responseAsString: Option[String]) { |
There was a problem hiding this comment.
This is kind of unfortunate but I guess it's a consequence of only having the Send at this point. Not seeing any great alternatives, but I guess we could build the string representation into the Send object itself. That or maybe we should just keep around the Response object a bit longer when request logging is enabled.
There was a problem hiding this comment.
We have various Send implementations thought, so it seems like it would be messier than this. Or am I missing something?
I avoided retaining the actual response object as it could be pretty large in some cases. An example is a down converted FetchResponse.
There was a problem hiding this comment.
There's really only 2-3 implementations of Send. What I had in mind was potentially adding the string representation as a member field which was set upon construction and surfaced through toString. Might not be any better than this option though, just shifts the ugliness elsewhere.
There was a problem hiding this comment.
There are 5 implementations of Send although not sure if we'd have to do it for all of them. Also, we only want to compute the toString eagerly if request logging is enabled. From that perspective, it seemed best to leave this ugliness in the RequestChannel classes instead of spreading it through other classes that shouldn't care about this.
There was a problem hiding this comment.
Yes, I agree. Just thinking through the other options.
For what it's worth, it seems like the only reason we keep around the request body is to log this message. That means we could do a similar trick and convert it to a string. I guess this is less important because we already have logic to free the records in produce requests though.
There was a problem hiding this comment.
OK, I'll file a separate JIRA for the request body changes.
There was a problem hiding this comment.
| @@ -103,15 +105,15 @@ object RequestChannel extends Logging { | |||
| if (apiRemoteCompleteTimeNanos < 0) | |||
| apiRemoteCompleteTimeNanos = responseCompleteTimeNanos | |||
|
|
|||
| def nanosToMs(nanos: Long) = math.max(TimeUnit.NANOSECONDS.toMillis(nanos), 0) | |||
| def nanosToMs(nanos: Long) = math.max(nanos, 0).toDouble / TimeUnit.MILLISECONDS.toNanos(1) | |||
There was a problem hiding this comment.
I am not sure we really need nanosecond precision for logging, especially since clocks don't provide nanosecond level accuracy. Would it make sense to either format the entries going into the request log or convert to micros to log with microsecond level precision? Btw, that was the intention in the previous code, I had just forgotten.
There was a problem hiding this comment.
Since we round the value to the nearest integer for the other case, it seems like the simplest is to convert to micros first.
ijuma
force-pushed
the
log-response-in-request-log
branch
from
ca107a2
to
e21bf18
Compare
ijuma
force-pushed
the
log-response-in-request-log
branch
from
e21bf18
to
cbdedd2
Compare
|
Merging to trunk. |
It's implemented such that there is no overhead if request logging is
disabled.
Also:
updateRequestMetricsformatarguments.