Uh oh!
There was an error while loading. Please reload this page.
HBASE-28175: Deep copy RpcLogDetails' param field - #5481
Merged
Conversation
Uh oh!
There was an error while loading. Please reload this page.
Apache-HBase
commented
Oct 26, 2023
💔 -1 overall
This message was automatically generated. |
rmdmattinglyforce-pushed
the
HBASE-28175-master
branch
from
October 26, 2023 16:54
0edc56f to
eafcd3fCompare| SlowLogParams that = (SlowLogParams) o; | ||
| return new EqualsBuilder().append(regionName, that.regionName).append(params, that.params) | ||
| .append("scan", scan).isEquals(); | ||
| .append(scan, that.scan).isEquals(); |
ContributorAuthor
There was a problem hiding this comment.
I also noticed this bug in the SlowLogParams equals implementation, but I don't think it's related to the slow log payload corruption that we've observed
virajjasani
left a comment
Contributor
There was a problem hiding this comment.
I doubt if we can write some real test for this, can you think of any @rmdmattingly?
rmdmattingly
commented
Oct 26, 2023
ContributorAuthor
It would be difficult to reliably reproduce the overwriting of the input buffer in a unit test, but maybe it's possible. We could probably write a unit test which confirms the copied nature of the message here |
virajjasani
self-requested a review
October 26, 2023 17:48
bbeaudreault
commented
Oct 26, 2023
Contributor
This might seem silly, but I wonder if you could at least do the simple test of:
This may not be our usual end-to-end test that proves the bug, but it at least proves the fix under the assumption that the bug is occurring periodically. |
rmdmattingly
commented
Oct 26, 2023
ContributorAuthor
Nice, I like that idea! I'm headed out on vacation tonight, but will add that test when I return later next week |
Apache-HBase
commented
Oct 26, 2023
💔 -1 overall
This message was automatically generated. |
bbeaudreault
commented
Oct 26, 2023
Contributor
An alternative approach here might be to find a way to call ByteBuffer.retain() when creating the SlowLogParams, and then ByteBuffer.release() when consuming in SlowLogService. That might be a little tricker, but would probably be better in terms of GC and time spent copying. It sort of depends on the rate of slow logs. Looking briefly at it, I think we could possibly utilize the method @Apache9 added to RpcCall in HBASE-22539 -- retainByWAL when enqueueing a RpcLogDetails, and then call releaseByWAL in SlowLogQueueService.consumeEventFromDisruptor. Obviously we'd need to rename the methods in that case. What do you think of that Duo? It seems like the exact same problem |
Apache-HBase
commented
Oct 26, 2023
🎊 +1 overall
This message was automatically generated. |
Apache-HBase
commented
Oct 27, 2023
🎊 +1 overall
This message was automatically generated. |
Apache-HBase
commented
Oct 27, 2023
🎊 +1 overall
This message was automatically generated. |
rmdmattingly
commented
Nov 2, 2023
Comment on lines
+67
to
+93
| @Test | ||
| public void itDeepCopiesRpcLogDetailsParams() throws IOException { | ||
| ByteBuffer buffer = ByteBuffer.allocate(scanRequest.toByteArray().length); | ||
| CodedInputStream cis = UnsafeByteOperations.unsafeWrap(buffer).newCodedInput(); | ||
| cis.enableAliasing(true); | ||
| buffer.put(scanRequest.toByteArray()); | ||
| Message.Builder messageBuilder = ClientProtos.ScanRequest.newBuilder(); | ||
| ProtobufUtil.mergeFrom(messageBuilder, cis, buffer.capacity()); | ||
| Message message = messageBuilder.build(); | ||
| RpcLogDetails rpcLogDetails = | ||
| new RpcLogDetails(getRpcCall(message), message, null, 0L, 0L, null, true, false); | ||
| // log's scan should be equal | ||
| ClientProtos.Scan logScan = ((ClientProtos.ScanRequest) rpcLogDetails.getParam()).getScan(); | ||
| assertEquals(logScan, scan); | ||
| // ensure we have a different byte array for testing | ||
| assertFalse(Arrays.equals(scanRequest.toByteArray(), otherScanRequest.toByteArray())); | ||
| // corrupt the underlying buffer | ||
| buffer.position(0); | ||
| buffer.put(otherScanRequest.toByteArray(), 0, otherScanRequest.toByteArray().length); | ||
| assertArrayEquals(otherScanRequest.toByteArray(), buffer.array()); | ||
| // log scan should still be original scan | ||
| assertEquals(logScan, scan); | ||
| } |
ContributorAuthor
There was a problem hiding this comment.
This test fails without this PR's changes to RpcLogDetails
Apache-HBase
commented
Nov 2, 2023
🎊 +1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 2, 2023
💔 -1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 2, 2023
💔 -1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 2, 2023
🎊 +1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 3, 2023
💔 -1 overall
This message was automatically generated. |
rmdmattingly
commented
Nov 3, 2023
ContributorAuthor
The test failures above are unrelated. I believe this is ready for review |
virajjasani
approved these changes
Nov 6, 2023
| this.param = param.newBuilderForType().mergeFrom(param.toByteArray()).build(); | ||
| } catch (InvalidProtocolBufferException e) { | ||
| LOG.error("Failed to parse protobuf for message {}", param, e); | ||
| if (this.param == null) { |
Contributor
There was a problem hiding this comment.
this would likely always be true right?
ContributorAuthor
There was a problem hiding this comment.
yeah, I can't imagine when it wouldn't be true so maybe we should just remove this
Apache-HBase
commented
Nov 6, 2023
🎊 +1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 6, 2023
💔 -1 overall
This message was automatically generated. |
Apache-HBase
commented
Nov 6, 2023
🎊 +1 overall
This message was automatically generated. |
virajjasani
approved these changes
Nov 6, 2023
virajjasani
left a comment
Contributor
There was a problem hiding this comment.
+1, anything from your side @bbeaudreault sir?
bbeaudreault
approved these changes
Nov 9, 2023
bbeaudreault pushed a commit
that referenced
this pull request
Nov 9, 2023
Signed-off-by: Viraj Jasani <vjasani@apache.org> Signed-off-by: Bryan Beaudreault <bbeaudreault@apache.org>
bbeaudreault pushed a commit
that referenced
this pull request
Nov 9, 2023
Signed-off-by: Viraj Jasani <vjasani@apache.org> Signed-off-by: Bryan Beaudreault <bbeaudreault@apache.org>
bbeaudreault pushed a commit
that referenced
this pull request
Nov 9, 2023
Signed-off-by: Viraj Jasani <vjasani@apache.org> Signed-off-by: Bryan Beaudreault <bbeaudreault@apache.org>
bbeaudreault pushed a commit
to HubSpot/hbase
that referenced
this pull request
Nov 9, 2023
…pache#5481) Signed-off-by: Viraj Jasani <vjasani@apache.org> Signed-off-by: Bryan Beaudreault <bbeaudreault@apache.org>
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 freeto 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.
The RpcLogDetails class represents a slow (or large) log event which will later be consumed by the SlowLogQueueService.
Right now the RpcLogDetails' param field points to the slow call's Message, and this Message is backed by a CodedInputStream which may be overwritten before the given log is consumed. This overwriting of the Message may result in slow query payloads for which the metadata derived post-consumption is inaccurate.
To solve this bug we need to deep copy the Message in the RpcLogDetails constructor. I have this bug reproduced in a QA environment and have confirmed that this resolves the issue.
cc @bbeaudreault@hgromer@eab148@bozzkar