Skip to content

Backport "HBASE-27155 Improvements to low level scanner tracing" to branch-2.5 - #4601

Closed
ndimiduk wants to merge 2 commits into
apache:branch-2.5from
ndimiduk:27153-low-level-scanner-tracing-branch-2.5
Closed

Backport "HBASE-27155 Improvements to low level scanner tracing" to branch-2.5#4601
ndimiduk wants to merge 2 commits into
apache:branch-2.5from
ndimiduk:27153-low-level-scanner-tracing-branch-2.5

Conversation

@ndimiduk

Copy link
Copy Markdown
Member

This branch starts with #4574 and then adds a translation of ndimiduk/hbase@93a6fed into otel span events.

How I think you might use this, @apurtell , is to set up tracing with the Logging Exporter, run your test bench, and then parse the logs to summon them into metrics.

@Apache-HBase

Copy link
Copy Markdown

💔 -1 overall

VoteSubsystemRuntimeComment
+0 🆗reexec1m 15sDocker mode activated.
_ Prechecks _
+1 💚dupname0m 1sNo case conflicting files found.
+1 💚hbaseanti0m 0sPatch does not have any anti-patterns.
+1 💚@author0m 0sThe patch does not contain any @author tags.
_ branch-2.5 Compile Tests _
+0 🆗mvndep0m 16sMaven dependency ordering for branch
+1 💚mvninstall3m 18sbranch-2.5 passed
+1 💚compile4m 33sbranch-2.5 passed
+1 💚checkstyle1m 13sbranch-2.5 passed
-1 ❌spotless0m 25sbranch has 21 errors when running spotless:check, run spotless:apply to fix.
+1 💚spotbugs3m 27sbranch-2.5 passed
_ Patch Compile Tests _
+0 🆗mvndep0m 10sMaven dependency ordering for patch
+1 💚mvninstall2m 41sthe patch passed
+1 💚compile4m 16sthe patch passed
+1 💚javac4m 16sthe patch passed
-0 ⚠️checkstyle0m 37shbase-server: The patch generated 3 new + 11 unchanged - 3 fixed = 14 total (was 14)
+1 💚whitespace0m 0sThe patch has no whitespace issues.
+1 💚hadoopcheck14m 1sPatch does not cause any errors with Hadoop 2.10.0 or 3.1.2 3.2.1.
-1 ❌spotless0m 27spatch has 21 errors when running spotless:check, run spotless:apply to fix.
+1 💚spotbugs3m 40sthe patch passed
_ Other Tests _
+1 💚asflicense0m 30sThe patch does not generate ASF License warnings.
48m 37s
SubsystemReport/Notes
DockerClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-general-check/output/Dockerfile
GITHUB PR#4601
Optional Testsdupname asflicense javac spotbugs hadoopcheck hbaseanti spotless checkstyle compile
unameLinux 92ca957238cc 5.4.0-1025-aws #25~18.04.1-Ubuntu SMP Fri Sep 11 12:03:04 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux
Build toolmaven
Personalitydev-support/hbase-personality.sh
git revisionbranch-2.5 / 3ca8484
Default JavaAdoptOpenJDK-1.8.0_282-b08
spotlesshttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-general-check/output/branch-spotless.txt
checkstylehttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-general-check/output/diff-checkstyle-hbase-server.txt
spotlesshttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-general-check/output/patch-spotless.txt
Max. process+thread count64 (vs. ulimit of 12500)
modulesC: hbase-common hbase-client hbase-server U: .
Console outputhttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/console
versionsgit=2.17.1 maven=3.6.3 spotbugs=4.2.2
Powered byApache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase

Copy link
Copy Markdown

🎊 +1 overall

VoteSubsystemRuntimeComment
+0 🆗reexec0m 53sDocker mode activated.
-0 ⚠️yetus0m 4sUnprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ branch-2.5 Compile Tests _
+0 🆗mvndep0m 19sMaven dependency ordering for branch
+1 💚mvninstall2m 51sbranch-2.5 passed
+1 💚compile1m 15sbranch-2.5 passed
+1 💚shadedjars4m 2sbranch has no errors when building our shaded downstream artifacts.
+1 💚javadoc0m 57sbranch-2.5 passed
_ Patch Compile Tests _
+0 🆗mvndep0m 15sMaven dependency ordering for patch
+1 💚mvninstall2m 29sthe patch passed
+1 💚compile1m 14sthe patch passed
+1 💚javac1m 14sthe patch passed
+1 💚shadedjars3m 57spatch has no errors when building our shaded downstream artifacts.
+1 💚javadoc0m 51sthe patch passed
_ Other Tests _
+1 💚unit1m 40shbase-common in the patch passed.
+1 💚unit2m 46shbase-client in the patch passed.
+1 💚unit175m 4shbase-server in the patch passed.
201m 29s
SubsystemReport/Notes
DockerClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR#4601
Optional Testsjavac javadoc unit shadedjars compile
unameLinux ccd56a4aa119 5.4.0-1071-aws #76~18.04.1-Ubuntu SMP Mon Mar 28 17:49:57 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build toolmaven
Personalitydev-support/hbase-personality.sh
git revisionbranch-2.5 / 3ca8484
Default JavaAdoptOpenJDK-11.0.10+9
Test Resultshttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/testReport/
Max. process+thread count2564 (vs. ulimit of 12500)
modulesC: hbase-common hbase-client hbase-server U: .
Console outputhttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/console
versionsgit=2.17.1 maven=3.6.3
Powered byApache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase

Copy link
Copy Markdown

🎊 +1 overall

VoteSubsystemRuntimeComment
+0 🆗reexec0m 53sDocker mode activated.
-0 ⚠️yetus0m 7sUnprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ branch-2.5 Compile Tests _
+0 🆗mvndep0m 14sMaven dependency ordering for branch
+1 💚mvninstall2m 25sbranch-2.5 passed
+1 💚compile1m 7sbranch-2.5 passed
+1 💚shadedjars4m 1sbranch has no errors when building our shaded downstream artifacts.
+1 💚javadoc0m 51sbranch-2.5 passed
_ Patch Compile Tests _
+0 🆗mvndep0m 12sMaven dependency ordering for patch
+1 💚mvninstall2m 16sthe patch passed
+1 💚compile1m 7sthe patch passed
+1 💚javac1m 7sthe patch passed
+1 💚shadedjars3m 56spatch has no errors when building our shaded downstream artifacts.
+1 💚javadoc0m 49sthe patch passed
_ Other Tests _
+1 💚unit1m 25shbase-common in the patch passed.
+1 💚unit2m 31shbase-client in the patch passed.
+1 💚unit180m 35shbase-server in the patch passed.
204m 11s
SubsystemReport/Notes
DockerClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/artifact/yetus-jdk8-hadoop2-check/output/Dockerfile
GITHUB PR#4601
Optional Testsjavac javadoc unit shadedjars compile
unameLinux 5a69f9a5efe8 5.4.0-1071-aws #76~18.04.1-Ubuntu SMP Mon Mar 28 17:49:57 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build toolmaven
Personalitydev-support/hbase-personality.sh
git revisionbranch-2.5 / 3ca8484
Default JavaAdoptOpenJDK-1.8.0_282-b08
Test Resultshttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/testReport/
Max. process+thread count2424 (vs. ulimit of 12500)
modulesC: hbase-common hbase-client hbase-server U: .
Console outputhttps://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4601/1/console
versionsgit=2.17.1 maven=3.6.3
Powered byApache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@apurtell

apurtell commented Jul 7, 2022

Copy link
Copy Markdown
Contributor

@ndimiduk It does make sense to me that we would decorate the spans with events, and not try to maintain counters, as did the original patch. I only did that because aggregate counts at the end of the RPC were sufficient for my needs then. If I had needed a log of events I would have had to do something more like this. It is nice to have a timeline of events recorded into the span(s) instead, in typical form for otel.

How I think you might use this, @apurtell , is to set up tracing with the Logging Exporter, run your test bench, and then parse the logs to summon them into metrics.

Agreed, converting events into metrics by logging and then counting occurrences over the logs is quite typical here. The events and the times at which they occur are the raw data that can serve several different approaches to analyzing the timeline.

I would approve this draft fwiw

@ndimiduk

Copy link
Copy Markdown
MemberAuthor

Okay, after too long of a delay, I have collected some data in which I have some amount confidence. The raw data and summaries are in this Google Sheet for your examination. The charts are pasted here for your reference.

Runtime (mins)
Read Latency, 95th Percentile (µs)
Read Latency, 99th Percentile (µs)

Test Methodology

I tested three different builds: a baseline (ecf758b), that baseline (ecf758b) + HBASE-27153, and that baseline (ecf758b) + HBASE-27153 + HBASE-27155. In all cases, the test is run with tracing disabled -- all that's measured here is the impact of the code changes made to facilitate manual instrumentation by each patch. The test run was a YCSB workload that I happened to have handy, with 20% writes and 80% random reads. The test runs for a little over 30 minutes. The data collected is the total test runtime, and the read latencies reported by YCSB at p95 and p99.

The test methodology was to first prepare a dataset by populating a pre-split table using the YCSB load feature, flush and major compact the table, snapshot the table. Each test iteration involved dropping the table, cloning the snapshot back into place, and then applying the test workload.

I kept an eye on cluster metrics as things ran. Client and server generally agree on number of requests served/sec. Each test, it took about 20 minutes for the block cache hit rate to climb from a starting point of 50% to the steady state of around 70%. I made an effort to exclude as much as possible the impact of compactions on the test results -- ASYNC_WAL was used, and dropping the table after each test run dropped the pending compaction work that accumulated via the write portion of the workload.

My Interpretation of results

The changes introduced with HBASE-27153 appear to have an overall positive impact on read throughput and latency, although in latency in particular, there is a disturbingly large amount of internal variance. HBASE-27155 appears to undo all of that improvement and then do additional harm.

It is my opinion that the regression of 2ms at p95 and 1ms at p99 is too expensive to accept for the inclusion of HBASE-27155.

Next Steps

We can conclude analysis here and decide to commit one or both patches. Or, we can attempt further analysis. The next analysis step I would suggest is collection and comparison of flame graphs at several points during the test period.

Please advise.

@apurtell

Copy link
Copy Markdown
Contributor

Thanks for doing this analysis @ndimiduk . I will note this on HBASE-27155 and resolve that issue. So I would propose the next steps here are:

  1. Proceed with HBASE-27153
  2. Do not proceed with HBASE-27155.

@apurtell

Copy link
Copy Markdown
Contributor

I resolved HBASE-27155 as WontFix so will close this PR too. All please feel free to reopen/unresolve if you'd like to pursue this at some later time.

@ndimiduk

Copy link
Copy Markdown
MemberAuthor

@apurtell Just for my own curiosity, and because I already have the test rig and I earlier did the work of forward porting your counter-based patch, I'm running it through the same cycles. And since I'm here, I'll also run rel/2.4.13.

@ndimiduk

Copy link
Copy Markdown
MemberAuthor

@apurtell Results from the counter-based patch and rel/2.4.13 are in the spreadsheet and charted, FYI.

Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

@ndimiduk@Apache-HBase@apurtell