fix: ensure instrumentation durations are unique during threaded executions #658
Conversation
This file contains 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
rabidpraxis
changed the title
roelbondoc
approved these changes
Jan 10, 2025
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
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.
We noticed some inconsistencies in the timing of some of our Insights events, so I ran some tests and was able to hackily replicate with multiple concurrent requests.
What I believe is happening is the
Honeybadger::NotificationSubscriberis shared between all threads of the web server, and since we were using an instance variable to set the start time, ifstartis called multiple times without a calledfinish, we override the time.This was a bear to test without getting really nasty. I opted to get sorta nasty and stub
Process.clock_gettimeto return an incrementing number only when called during thestartmethod. This test is very brittle since it relies on caller stack. For concurrent executions, this would be overridden and the final durations would have duplicates. Please let me know if you have a better way to test this.For the fix, I stored the start time in the payload, as that should be unique to each instrumentation dispatch.