Skip to content

Conversation

@ndimiduk
Copy link
Member

Take another pass through tracing of the read path, make adjustments accordingly. One of the major concerns raised previously is that we create a span for every block access. Start by simplifying this to trace events and see what else comes up.

Block-level and stream-level interactions are represented as span events with attached attributes (that's otel terminology for "structured logs", attached to the spans). I made an effort to surface information that an operator might be interested in while diagnosing slow read performance, and details that the previous generation of dev had already seen fit to surface via trace-level logging. We no longer emit spans for HFileReaderImpl.readBlock. I hope this is a good compromise between visibility and performance.

Also added a span context for block-cache pre-fetching.

@ndimiduk
Copy link
Member Author

These are some screenshots of traces emitted by a build of branch-2 plus this patch, running in pseudo-distributed mode, sent to a Jaeger backed. Notice that the span events are marked as lines on spans. See the attributes on those event.s

Screen Shot 2022-06-23 at 2 15 57 PM

Screen Shot 2022-06-23 at 2 16 25 PM

@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

Copy link
Contributor

@apurtell apurtell left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wish we didn't have to pass the scan attribute builder through as an extra parameter to methods that don't care about tracing per se, they simply exist on the traced path. Is it possible to use threadlocals or some otel notion of thread context for these? Or is that an anti-pattern?

@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

@ndimiduk
Copy link
Member Author

@apurtell

I wish we didn't have to pass the scan attribute builder through as an extra parameter to methods that don't care about tracing per se, they simply exist on the traced path.

The reason that I have to pass this attributes object around is that I'm providing context that is eventually annotated to a span "event" -- essentially a log line. Otel API lets me stuff arbitrary attributes into a thread local for span attributes, not for span event attributes.

Is it possible to use threadlocals or some otel notion of thread context for these? Or is that an anti-pattern?

I am also not a fan of the current approach. Introducing a ThreadLocal for this purpose that is inspected at arbitrary code points seems ham-handed to me. At the very least, it should somehow be limited in scope to the current request, not the current thread. Let me see if I can find a better solution.

@ndimiduk ndimiduk force-pushed the 27153-trace-read-path branch from 74de7bb to 3e73a7e Compare June 28, 2022 12:20
@ndimiduk
Copy link
Member Author

@apurtell I changed the implementation to use the otel Context for propagating the additional information I wanted, without changing the method signatures. I'm not sure if this is intended use of the otel api or not...

@ndimiduk ndimiduk requested a review from apurtell June 28, 2022 12:24
@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

@Apache-HBase

This comment was marked as outdated.

@apurtell
Copy link
Contributor

apurtell commented Jul 1, 2022

Approved. I like the

 final AttributesBuilder attributesBuilder = builderFromContext(Context.current());
 attributesBuilder...

style way of building attributes along a method call chain without adding the builder as a method parameter.

@ndimiduk ndimiduk force-pushed the 27153-trace-read-path branch from 3e73a7e to 25aa61a Compare July 7, 2022 14:35
@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 1m 32s Docker mode activated.
_ Prechecks _
+1 💚 dupname 0m 0s No case conflicting files found.
+1 💚 hbaseanti 0m 0s Patch does not have any anti-patterns.
+1 💚 @author 0m 0s The patch does not contain any @author tags.
_ master Compile Tests _
+0 🆗 mvndep 0m 23s Maven dependency ordering for branch
+1 💚 mvninstall 3m 32s master passed
+1 💚 compile 4m 35s master passed
+1 💚 checkstyle 1m 10s master passed
+1 💚 spotless 0m 49s branch has no errors when running spotless:check.
+1 💚 spotbugs 3m 5s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 12s Maven dependency ordering for patch
+1 💚 mvninstall 2m 48s the patch passed
+1 💚 compile 3m 56s the patch passed
+1 💚 javac 3m 56s the patch passed
+1 💚 checkstyle 1m 17s the patch passed
+1 💚 whitespace 0m 0s The patch has no whitespace issues.
+1 💚 hadoopcheck 17m 31s Patch does not cause any errors with Hadoop 3.1.2 3.2.2 3.3.1.
+1 💚 spotless 1m 1s patch has no errors when running spotless:check.
+1 💚 spotbugs 4m 23s the patch passed
_ Other Tests _
+1 💚 asflicense 0m 35s The patch does not generate ASF License warnings.
54m 45s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/artifact/yetus-general-check/output/Dockerfile
GITHUB PR #4572
Optional Tests dupname asflicense javac spotbugs hadoopcheck hbaseanti spotless checkstyle compile
uname Linux dfb41767a851 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 tool maven
Personality dev-support/hbase-personality.sh
git revision master / 6886d02
Default Java AdoptOpenJDK-1.8.0_282-b08
Max. process+thread count 64 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/console
versions git=2.17.1 maven=3.6.3 spotbugs=4.2.2
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

💔 -1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 1m 6s Docker mode activated.
-0 ⚠️ yetus 0m 2s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
+0 🆗 mvndep 0m 14s Maven dependency ordering for branch
+1 💚 mvninstall 2m 52s master passed
+1 💚 compile 1m 20s master passed
+1 💚 shadedjars 4m 38s branch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 1m 1s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 10s Maven dependency ordering for patch
+1 💚 mvninstall 2m 40s the patch passed
+1 💚 compile 1m 13s the patch passed
+1 💚 javac 1m 13s the patch passed
+1 💚 shadedjars 4m 19s patch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 0m 56s the patch passed
_ Other Tests _
+1 💚 unit 1m 36s hbase-common in the patch passed.
+1 💚 unit 1m 27s hbase-client in the patch passed.
-1 ❌ unit 231m 56s hbase-server in the patch failed.
257m 52s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/artifact/yetus-jdk8-hadoop3-check/output/Dockerfile
GITHUB PR #4572
Optional Tests javac javadoc unit shadedjars compile
uname Linux 3a2f1d160cdd 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 tool maven
Personality dev-support/hbase-personality.sh
git revision master / 6886d02
Default Java AdoptOpenJDK-1.8.0_282-b08
unit https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/artifact/yetus-jdk8-hadoop3-check/output/patch-unit-hbase-server.txt
Test Results https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/testReport/
Max. process+thread count 3026 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/console
versions git=2.17.1 maven=3.6.3
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

💔 -1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 1m 46s Docker mode activated.
-0 ⚠️ yetus 0m 2s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
+0 🆗 mvndep 0m 6s Maven dependency ordering for branch
+1 💚 mvninstall 4m 17s master passed
+1 💚 compile 2m 9s master passed
+1 💚 shadedjars 4m 55s branch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 1m 31s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 15s Maven dependency ordering for patch
+1 💚 mvninstall 4m 9s the patch passed
+1 💚 compile 2m 10s the patch passed
+1 💚 javac 2m 10s the patch passed
+1 💚 shadedjars 5m 50s patch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 1m 19s the patch passed
_ Other Tests _
+1 💚 unit 2m 51s hbase-common in the patch passed.
+1 💚 unit 2m 4s hbase-client in the patch passed.
-1 ❌ unit 272m 30s hbase-server in the patch failed.
308m 17s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR #4572
Optional Tests javac javadoc unit shadedjars compile
uname Linux b934934803c7 5.4.0-90-generic #101-Ubuntu SMP Fri Oct 15 20:00:55 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / 6886d02
Default Java AdoptOpenJDK-11.0.10+9
unit https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/artifact/yetus-jdk11-hadoop3-check/output/patch-unit-hbase-server.txt
Test Results https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/testReport/
Max. process+thread count 2567 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/4/console
versions git=2.17.1 maven=3.6.3
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@apurtell
Copy link
Contributor

apurtell commented Jul 7, 2022

TestAsyncTableScan.testReverseScanNoStopKey[1: scan=batch] failure seems relevant.

@ndimiduk ndimiduk force-pushed the 27153-trace-read-path branch from 25aa61a to 38ed920 Compare August 1, 2022 11:49
@ndimiduk
Copy link
Member Author

ndimiduk commented Aug 1, 2022

TestAsyncTableScan.testReverseScanNoStopKey[1: scan=batch] failure seems relevant.

This failure is baffling to me. The assertion failed because a span with the name TracedScanResultConsumer#onComplete was not found in the collection. However, you can see that a span of that name is printed in the DEBUG logging!

Signed-off-by: Andrew Purtell <apurtell@apache.org>
@ndimiduk ndimiduk force-pushed the 27153-trace-read-path branch from 38ed920 to 0bf363e Compare August 1, 2022 11:57
@Apache-HBase
Copy link

🎊 +1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 3m 28s Docker mode activated.
_ Prechecks _
+1 💚 dupname 0m 0s No case conflicting files found.
+1 💚 hbaseanti 0m 0s Patch does not have any anti-patterns.
+1 💚 @author 0m 0s The patch does not contain any @author tags.
_ master Compile Tests _
+0 🆗 mvndep 0m 51s Maven dependency ordering for branch
+1 💚 mvninstall 2m 22s master passed
+1 💚 compile 3m 24s master passed
+1 💚 checkstyle 0m 51s master passed
+1 💚 spotless 0m 42s branch has no errors when running spotless:check.
+1 💚 spotbugs 2m 14s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 10s Maven dependency ordering for patch
+1 💚 mvninstall 2m 29s the patch passed
+1 💚 compile 4m 6s the patch passed
+1 💚 javac 4m 6s the patch passed
+1 💚 checkstyle 1m 4s the patch passed
+1 💚 whitespace 0m 0s The patch has no whitespace issues.
+1 💚 hadoopcheck 13m 38s Patch does not cause any errors with Hadoop 3.1.2 3.2.2 3.3.1.
+1 💚 spotless 0m 54s patch has no errors when running spotless:check.
+1 💚 spotbugs 4m 17s the patch passed
_ Other Tests _
+1 💚 asflicense 0m 39s The patch does not generate ASF License warnings.
48m 3s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/artifact/yetus-general-check/output/Dockerfile
GITHUB PR #4572
Optional Tests dupname asflicense javac spotbugs hadoopcheck hbaseanti spotless checkstyle compile
uname Linux a9ae449a9f06 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 tool maven
Personality dev-support/hbase-personality.sh
git revision master / e8c14ee
Default Java AdoptOpenJDK-1.8.0_282-b08
Max. process+thread count 60 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/console
versions git=2.17.1 maven=3.6.3 spotbugs=4.2.2
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

💔 -1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 1m 4s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
+0 🆗 mvndep 0m 17s Maven dependency ordering for branch
+1 💚 mvninstall 2m 42s master passed
+1 💚 compile 1m 26s master passed
+1 💚 shadedjars 3m 44s branch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 0m 58s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 14s Maven dependency ordering for patch
+1 💚 mvninstall 2m 41s the patch passed
+1 💚 compile 1m 23s the patch passed
+1 💚 javac 1m 23s the patch passed
+1 💚 shadedjars 3m 44s patch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 0m 59s the patch passed
_ Other Tests _
+1 💚 unit 1m 54s hbase-common in the patch passed.
+1 💚 unit 1m 23s hbase-client in the patch passed.
-1 ❌ unit 208m 39s hbase-server in the patch failed.
233m 22s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/artifact/yetus-jdk11-hadoop3-check/output/Dockerfile
GITHUB PR #4572
Optional Tests javac javadoc unit shadedjars compile
uname Linux 868547b198ce 5.4.0-122-generic #138-Ubuntu SMP Wed Jun 22 15:00:31 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / e8c14ee
Default Java AdoptOpenJDK-11.0.10+9
unit https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/artifact/yetus-jdk11-hadoop3-check/output/patch-unit-hbase-server.txt
Test Results https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/testReport/
Max. process+thread count 2442 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/console
versions git=2.17.1 maven=3.6.3
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@Apache-HBase
Copy link

💔 -1 overall

Vote Subsystem Runtime Comment
+0 🆗 reexec 0m 35s Docker mode activated.
-0 ⚠️ yetus 0m 3s Unprocessed flag(s): --brief-report-file --spotbugs-strict-precheck --whitespace-eol-ignore-list --whitespace-tabs-ignore-list --quick-hadoopcheck
_ Prechecks _
_ master Compile Tests _
+0 🆗 mvndep 0m 12s Maven dependency ordering for branch
+1 💚 mvninstall 2m 30s master passed
+1 💚 compile 1m 3s master passed
+1 💚 shadedjars 4m 1s branch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 0m 47s master passed
_ Patch Compile Tests _
+0 🆗 mvndep 0m 11s Maven dependency ordering for patch
+1 💚 mvninstall 2m 12s the patch passed
+1 💚 compile 1m 3s the patch passed
+1 💚 javac 1m 3s the patch passed
+1 💚 shadedjars 4m 0s patch has no errors when building our shaded downstream artifacts.
+1 💚 javadoc 0m 46s the patch passed
_ Other Tests _
+1 💚 unit 1m 23s hbase-common in the patch passed.
+1 💚 unit 1m 7s hbase-client in the patch passed.
-1 ❌ unit 228m 2s hbase-server in the patch failed.
250m 4s
Subsystem Report/Notes
Docker ClientAPI=1.41 ServerAPI=1.41 base: https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/artifact/yetus-jdk8-hadoop3-check/output/Dockerfile
GITHUB PR #4572
Optional Tests javac javadoc unit shadedjars compile
uname Linux 24056846fce9 5.4.0-1081-aws #88~18.04.1-Ubuntu SMP Thu Jun 23 16:29:17 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
Build tool maven
Personality dev-support/hbase-personality.sh
git revision master / e8c14ee
Default Java AdoptOpenJDK-1.8.0_282-b08
unit https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/artifact/yetus-jdk8-hadoop3-check/output/patch-unit-hbase-server.txt
Test Results https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/testReport/
Max. process+thread count 2629 (vs. ulimit of 30000)
modules C: hbase-common hbase-client hbase-server U: .
Console output https://ci-hbase.apache.org/job/HBase-PreCommit-GitHub-PR/job/PR-4572/5/console
versions git=2.17.1 maven=3.6.3
Powered by Apache Yetus 0.12.0 https://yetus.apache.org

This message was automatically generated.

@ndimiduk ndimiduk merged commit d734acc into apache:master Aug 2, 2022
@ndimiduk ndimiduk deleted the 27153-trace-read-path branch August 2, 2022 12:09
Sign up for free to 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.

4 participants