Merged
Conversation
In elastic#96205 we started recording the start time of the authn phase of REST request processing, because this happens too early to even start a span for the request. However we capture the threadpool's cached time which can be 200ms slow, yielding spans that appear much longer than they should. This commit moves to capturing the time using `System.currentTimeMillis` to avoid this problem.
Collaborator
|
Pinging @elastic/es-core-infra (Team:Core/Infra) |
Collaborator
|
Hi @DaveCTurner, I've created a changelog YAML for you. |
pugnascotia
reviewed
Aug 1, 2023
| // the request's thread-context must always be populated (by calling this method) before undergoing any request related processing | ||
| // we use this opportunity to first record the request processing start time | ||
| threadContext.putTransient(Task.TRACE_START_TIME, Instant.ofEpochMilli(threadPool.absoluteTimeInMillis())); | ||
| threadContext.putTransient(Task.TRACE_START_TIME, Instant.ofEpochMilli(System.currentTimeMillis())); |
Contributor
There was a problem hiding this comment.
The one downside of this is testability - don't we have a Clock that we can inject? But maybe that's overkill and this is good enough.
Member
Author
There was a problem hiding this comment.
Eh we probably could (indeed we could make a ThreadPool#rawAbsoluteTimeInMillis to parallel ThreadPool#rawRelativeTimeInMillis). Not sure it's really worth it here, at least not unless we see this test actually failing.
pugnascotia
approved these changes
Aug 1, 2023
Member
|
I think it would make sense to backport this to 8.9.1, WDYT? |
Member
Author
|
Sure, I can do that. |
DaveCTurner
added a commit
that referenced
this pull request
Aug 2, 2023
In #96205 we started recording the start time of the authn phase of REST request processing, because this happens too early to even start a span for the request. However we capture the threadpool's cached time which can be 200ms slow, yielding spans that appear much longer than they should. This commit moves to capturing the time using `System.currentTimeMillis` to avoid this problem. Backport of #98113 to 8.9
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
4 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
In #96205 we started recording the start time of the authn phase of REST
request processing, because this happens too early to even start a span
for the request. However we capture the threadpool's cached time which
can be 200ms slow, yielding spans that appear much longer than they
should. This commit moves to capturing the time using
System.currentTimeMillisto avoid this problem.