[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Add copy buttons to all
 blocks\n(function() {\n function addCopyButtons() {\n document.querySelectorAll('pre code').forEach(function(codeBlock) {\n if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;\n codeBlock.parentElement.setAttribute('data-copy-added', 'true');\n \n var btn = document.createElement('button');\n btn.textContent = 'Copy';\n btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';\n btn.onmouseover = function() { this.style.opacity = '1'; };\n btn.onmouseout = function() { this.style.opacity = '0.7'; };\n btn.onclick = function() {\n navigator.clipboard.writeText(codeBlock.textContent).then(function() {\n btn.textContent = 'Copied!';\n setTimeout(function() { btn.textContent = 'Copy'; }, 1500);\n });\n };\n codeBlock.parentElement.style.position = 'relative';\n codeBlock.parentElement.appendChild(btn);\n });\n }\n \n addCopyButtons();\n \n // Re-run on dynamic content\n var observer = new MutationObserver(addCopyButtons);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Add Copy Buttons to Code Blocks");
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Force GitHub README to respect dark mode\n(function() {\n var style = document.createElement('style');\n style.textContent = '\n .markdown-body {\n color-scheme: dark light;\n }\n .markdown-body pre { background: #161b22 !important; }\n .markdown-body code { background: rgba(110, 118, 129, 0.4) !important; }\n .markdown-body table th, .markdown-body table td { border-color: #30363d !important; }\n .markdown-body img { background: #0d1117; }\n .markdown-body blockquote { border-left-color: #8b949e; }\n .markdown-body hr { border-color: #30363d; }\n ';\n document.head.appendChild(style);\n})();", "GitHub Dark Mode README Fix"); } } catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Highlight search terms from Google/DuckDuckGo/Bing referrer\n(function() {\n var ref = document.referrer;\n var terms = [];\n \n if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) {\n var url = new URL(ref);\n var q = url.searchParams.get('q') || url.searchParams.get('p');\n if (q) {\n terms = q.split(/\\s+/).filter(function(t) { return t.length > 2; });\n }\n }\n \n if (terms.length === 0) return;\n \n var style = document.createElement('style');\n style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }';\n document.head.appendChild(style);\n \n function highlight(node) {\n if (node.nodeType === 3) { // text node\n var text = node.textContent;\n var found = false;\n terms.forEach(function(term) {\n var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\\]\\\\]/g, '\\\\') + ')', 'gi');\n if (regex.test(text)) {\n found = true;\n var frag = document.createDocumentFragment();\n var parts = text.split(regex);\n parts.forEach(function(part, i) {\n if (i % 2 === 0) {\n frag.appendChild(document.createTextNode(part));\n } else {\n var span = document.createElement('span');\n span.className = 'userscript-highlight';\n span.textContent = part;\n frag.appendChild(span);\n }\n });\n node.parentNode.replaceChild(frag, node);\n }\n });\n } else if (node.nodeType === 1 && node.childNodes) { // element\n var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT'];\n if (!skipTags.includes(node.tagName)) {\n Array.from(node.childNodes).forEach(highlight);\n }\n }\n }\n \n highlight(document.body);\n \n // Re-highlight on dynamic content\n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1 || node.nodeType === 3) highlight(node);\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Highlight Search Terms"); } } catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Strip utm_, fbclid, gclid, etc. from all links on page\n(function() {\n var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content',\n 'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid',\n 'ref', 'ref_src', 'source', 'medium', 'campaign'];\n \n function cleanUrl(url) {\n try {\n var u = new URL(url, window.location.origin);\n var changed = false;\n trackingParams.forEach(function(p) {\n if (u.searchParams.has(p)) {\n u.searchParams.delete(p);\n changed = true;\n }\n });\n return changed ? u.toString() : url;\n } catch (e) {\n return url;\n }\n }\n \n function cleanLinks() {\n document.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n \n cleanLinks();\n \n var observer = new MutationObserver(function(mutations) {\n mutations.forEach(function(m) {\n m.addedNodes.forEach(function(node) {\n if (node.nodeType === 1) {\n if (node.tagName === 'A') cleanLinks();\n node.querySelectorAll('a[href]').forEach(function(a) {\n var clean = cleanUrl(a.href);\n if (clean !== a.href) a.href = clean;\n });\n }\n });\n });\n });\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "Remove Tracking Parameters from Links"); } } catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); } })(); (function(){ try { var __m = "youtube.com"; var __re = new RegExp('^' + "youtube\\.com" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Auto-enable theater mode on YouTube\n(function() {\n function tryTheater() {\n var btn = document.querySelector('button[aria-label=\"Theater mode\"], ytd-player #player button[title=\"Theater mode\"]');\n if (btn && !btn.classList.contains('activated')) {\n btn.click();\n }\n }\n \n // Try immediately\n tryTheater();\n \n // Try after navigation (SPA)\n var lastUrl = location.href;\n setInterval(function() {\n if (location.href !== lastUrl) {\n lastUrl = location.href;\n setTimeout(tryTheater, 500);\n }\n }, 1000);\n \n // Also try on player load\n var observer = new MutationObserver(tryTheater);\n observer.observe(document.body, { childList: true, subtree: true });\n})();", "YouTube Theater Mode Default"); } } catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Remove or un-stick sticky/fixed headers that block content\n(function() {\n function unstick() {\n document.querySelectorAll('header, nav, [role=\"banner\"], .header, .navbar, .sticky, .fixed-top, [style*=\"position: fixed\"], [style*=\"position:sticky\"]').forEach(function(el) {\n if (el.style.position === 'fixed' || el.style.position === 'sticky' || \n getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') {\n el.style.position = 'static';\n el.style.top = 'auto';\n el.style.zIndex = 'auto';\n }\n });\n }\n \n unstick();\n \n var observer = new MutationObserver(unstick);\n observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] });\n})();", "Kill Sticky Headers"); } } catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); } })(); (function(){ try { var __m = "*"; var __re = new RegExp('^' + ".*" + '
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox
, 'i'); if (__m === '*' || __re.test(location.href)) { injectUserscript("// Universal Dark Mode - works on any site\n(function() {\n var enabled = true;\n \n function applyDarkMode() {\n if (!enabled) return;\n \n // Create style element if it doesn't exist\n var style = document.getElementById('universal-dark-mode-style');\n if (!style) {\n style = document.createElement('style');\n style.id = 'universal-dark-mode-style';\n document.head.appendChild(style);\n }\n \n // Dark mode CSS - inverts colors but preserves images/video\n style.textContent = '\n /* Invert everything except media */\n html {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #1a1a2e !important;\n }\n \n /* Restore images, videos, iframes, canvas */\n img, video, iframe, canvas, svg, picture, [style*=\"background-image\"] {\n filter: invert(1) hue-rotate(180deg) !important;\n }\n \n /* Preserve specific elements that should not be inverted */\n .no-dark-mode, .no-dark-mode *,\n [data-theme=\"light\"], [data-theme=\"light\"],\n .ace_editor, .ace_editor *,\n .CodeMirror, .CodeMirror *,\n .monaco-editor, .monaco-editor *,\n .markdown-body pre, .markdown-body pre *,\n .highlight, .highlight *,\n pre code, pre code * {\n filter: none !important;\n }\n \n /* Fix common UI elements */\n .modal, .popup, .dropdown-menu, .tooltip, .popover {\n filter: invert(1) hue-rotate(180deg) !important;\n background: #2d2d44 !important;\n border-color: #444 !important;\n }\n \n /* Scrollbars */\n ::-webkit-scrollbar { background: #1a1a2e !important; }\n ::-webkit-scrollbar-thumb { background: #444 !important; }\n ::-webkit-scrollbar-thumb:hover { background: #555 !important; }\n \n /* Selection */\n ::selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; }\n ';\n }\n \n function removeDarkMode() {\n var style = document.getElementById('universal-dark-mode-style');\n if (style) style.remove();\n }\n \n // Toggle with Alt+Shift+D\n document.addEventListener('keydown', function(e) {\n if (e.altKey && e.shiftKey && e.key === 'D') {\n e.preventDefault();\n enabled = !enabled;\n if (enabled) {\n applyDarkMode();\n console.log('[Universal Dark Mode] Enabled');\n } else {\n removeDarkMode();\n console.log('[Universal Dark Mode] Disabled');\n }\n }\n });\n \n // Apply on load\n applyDarkMode();\n \n // Re-apply on dynamic content\n var observer = new MutationObserver(function(mutations) {\n if (enabled && !document.getElementById('universal-dark-mode-style')) {\n applyDarkMode();\n }\n });\n observer.observe(document.head, { childList: true });\n \n console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle');\n})();", "Universal Dark Mode"); } } catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); } })(); })();
Skip to content

[improvement] Add JMH benchmark project - #176

Closed
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh
Closed

[improvement] Add JMH benchmark project#176
schlosna wants to merge 2 commits into
palantir:developfrom
schlosna:ds/jmh

Conversation

@schlosna

Copy link
Copy Markdown
Contributor

Before this PR

There were no benchmarks for measuring tracing performance overhead and implementation efficiency.

After this PR

There is now a tracing-benchmarks module to house JMH benchmarks. See #167 and #168 where these benchmarks would be useful.

Closes#169

@schlosna
schlosna requested a review from a team as a code ownerJune 14, 2019 17:02
@schlosna

Copy link
Copy Markdown
ContributorAuthor

@carterkozak@wenhoujx for SA

@schlosna

Copy link
Copy Markdown
ContributorAuthor

Some initial results from running ./gradlew jmh locally.

# JMH version: 1.21
# VM version: JDK 1.8.0_202, Java HotSpot(TM) 64-Bit Server VM, 25.202-b08
# Run complete. Total time: 00:01:04
REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 5.623 ± 0.306 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.018 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 1848.784 ± 343.535 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 8456.344 ± 1524.417 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1520.001 ± 0.003 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space avgt 5 8604.525 ± 2173.250 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1546.303 ± 222.998 B/op
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.196 ± 0.214 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.035 ± 0.039 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 66.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 49.000 ms
TracingBenchmark.undecidedCallable avgt 5 1565.075 ± 105.311 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 8359.815 ± 630.468 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1275.215 ± 0.113 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space avgt 5 8453.170 ± 111.997 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1289.864 ± 101.549 B/op
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space avgt 5 0.254 ± 0.220 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.039 ± 0.033 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 50.000 ms
TracingBenchmark.unsampledCallable avgt 5 1978.725 ± 129.672 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 6713.013 ± 390.855 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1248.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space avgt 5 6821.272 ± 587.137 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Eden_Space.norm avgt 5 1268.285 ± 116.842 B/op
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space avgt 5 0.258 ± 0.393 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.PS_Survivor_Space.norm avgt 5 0.048 ± 0.074 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 71.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 50.000 ms

@wenhoujx

Copy link
Copy Markdown
Contributor

i prefer this PR over mine #175 .

@schlosna

Copy link
Copy Markdown
ContributorAuthor

And OpenJDK 11:

# JMH version: 1.21
# VM version: JDK 11.0.2, OpenJDK 64-Bit Server VM, 11.0.2+9
Benchmark Mode Cnt Score Error Units
TracingBenchmark.raw avgt 5 6.636 ± 0.897 ns/op
TracingBenchmark.raw:·gc.alloc.rate avgt 5 0.007 ± 0.013 MB/sec
TracingBenchmark.raw:·gc.alloc.rate.norm avgt 5 ≈ 10⁻⁵ B/op
TracingBenchmark.raw:·gc.count avgt 5 ≈ 0 counts
TracingBenchmark.sampledCallable avgt 5 2495.817 ± 111.901 ns/op
TracingBenchmark.sampledCallable:·gc.alloc.rate avgt 5 6109.333 ± 250.925 MB/sec
TracingBenchmark.sampledCallable:·gc.alloc.rate.norm avgt 5 1488.021 ± 0.163 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space avgt 5 6235.575 ± 1220.997 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1519.263 ± 334.987 B/op
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.007 ± 0.006 MB/sec
TracingBenchmark.sampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.001 B/op
TracingBenchmark.sampledCallable:·gc.count avgt 5 53.000 counts
TracingBenchmark.sampledCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.undecidedCallable avgt 5 2118.867 ± 567.305 ns/op
TracingBenchmark.undecidedCallable:·gc.alloc.rate avgt 5 6071.679 ± 1537.381 MB/sec
TracingBenchmark.undecidedCallable:·gc.alloc.rate.norm avgt 5 1247.190 ± 0.154 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space avgt 5 6148.061 ± 1191.902 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1264.324 ± 153.069 B/op
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen avgt 5 0.008 ± 0.017 MB/sec
TracingBenchmark.undecidedCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.004 B/op
TracingBenchmark.undecidedCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.undecidedCallable:·gc.time avgt 5 59.000 ms
TracingBenchmark.unsampledCallable avgt 5 2164.710 ± 484.378 ns/op
TracingBenchmark.unsampledCallable:·gc.alloc.rate avgt 5 5779.937 ± 1255.292 MB/sec
TracingBenchmark.unsampledCallable:·gc.alloc.rate.norm avgt 5 1216.001 ± 0.003 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space avgt 5 5809.945 ± 2155.020 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Eden_Space.norm avgt 5 1220.637 ± 230.663 B/op
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen avgt 5 0.009 ± 0.010 MB/sec
TracingBenchmark.unsampledCallable:·gc.churn.G1_Old_Gen.norm avgt 5 0.002 ± 0.002 B/op
TracingBenchmark.unsampledCallable:·gc.count avgt 5 70.000 counts
TracingBenchmark.unsampledCallable:·gc.time avgt 5 59.000 ms

Comment threadbuild.gradle
options.errorprone.errorproneArgs += [
'-Werror',
'-Xlint:deprecation',
'-Xlint:unchecked',

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

👍

}
}

apply plugin: 'me.champeau.gradle.jmh'

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Can replace the combination of the buildscript block and this apply plugin line with this, since we're pulling from plugins.gradle.org:

plugins {
id "me.champeau.gradle.jmh" version "0.4.7"
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Also I'd quite like to keep the convention of declaring all plugin versions in the root level build.gradle, so there's just one place for people to look to see what functionality a project uses

@Benchmark
public static Object unsampledCallable() throws Exception {
return unsampledCallable.call();
}

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

These benchmarks all test starting and completing a trace, it's significantly more common to start/complete spans inside of a single trace, it would be helpful to measure creation+completion of a span inside of traces that are and aren't sampled.

In one large internal product in particular, it's not uncommon to have several thousand spans per trace.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Perhaps we could wrap the callable in ~100 callables of the form

() -> {
Tracer.startSpan("span");
try {
delegate.call();
} finally {
Tracer.fastCompleteSpan();
}
}

bulldozer-botBot pushed a commit that referenced this pull request Jun 19, 2019
<!-- PR title should start with '[fix]', '[improvement]' or '[break]' if this PR would cause a patch, minor or major SemVer bump. Omit the prefix if this PR doesn't warrant a standalone release. -->
add span benchmarks according to @carterkozak 's comments on #176 remove ## Before this PR
<!-- Describe the problem you encountered with the current state of the world (or link to an issue) and why it's important to fix now. -->
## After this PR
<!-- Describe at a high-level why this approach is better. -->
<!-- Reference any existing GitHub issues, e.g. 'fixes #000' or 'relevant to #000' -->
```
Benchmark (observability) Mode Cnt Score Error Units
TracingBenchmark.nestedSpans SAMPLE avgt 3 51266.154 ± 19461.304 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate SAMPLE avgt 3 2598.879 ± 978.792 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm SAMPLE avgt 3 40760.031 ± 1.141 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space SAMPLE avgt 3 2707.659 ± 1382.288 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm SAMPLE avgt 3 42470.187 ± 19619.815 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space SAMPLE avgt 3 0.056 ± 0.469 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm SAMPLE avgt 3 0.890 ± 7.573 B/op
TracingBenchmark.nestedSpans:·gc.count SAMPLE avgt 3 22.000 counts
TracingBenchmark.nestedSpans:·gc.time SAMPLE avgt 3 28.000 ms
TracingBenchmark.nestedSpans DO_NOT_SAMPLE avgt 3 26749.119 ± 17733.671 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate DO_NOT_SAMPLE avgt 3 2618.135 ± 1713.586 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm DO_NOT_SAMPLE avgt 3 21416.022 ± 0.539 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space DO_NOT_SAMPLE avgt 3 2664.780 ± 3436.299 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm DO_NOT_SAMPLE avgt 3 21780.010 ± 14872.970 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space DO_NOT_SAMPLE avgt 3 0.128 ± 1.580 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm DO_NOT_SAMPLE avgt 3 1.062 ± 13.821 B/op
TracingBenchmark.nestedSpans:·gc.count DO_NOT_SAMPLE avgt 3 65.000 counts
TracingBenchmark.nestedSpans:·gc.time DO_NOT_SAMPLE avgt 3 78.000 ms
TracingBenchmark.nestedSpans UNDECIDED avgt 3 30374.624 ± 7959.930 ns/op
TracingBenchmark.nestedSpans:·gc.alloc.rate UNDECIDED avgt 3 2442.989 ± 677.177 MB/sec
TracingBenchmark.nestedSpans:·gc.alloc.rate.norm UNDECIDED avgt 3 22713.026 ± 15.117 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space UNDECIDED avgt 3 2415.657 ± 1132.967 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Eden_Space.norm UNDECIDED avgt 3 22458.167 ± 7539.764 B/op
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space UNDECIDED avgt 3 0.160 ± 1.415 MB/sec
TracingBenchmark.nestedSpans:·gc.churn.PS_Survivor_Space.norm UNDECIDED avgt 3 1.498 ± 13.569 B/op
TracingBenchmark.nestedSpans:·gc.count UNDECIDED avgt 3 62.000 counts
TracingBenchmark.nestedSpans:·gc.time UNDECIDED avgt 3 69.000 ms
```
@carterkozak

Copy link
Copy Markdown
Contributor

Closing in favor of #179 based on this implementation, thanks!

@schlosna
schlosna deleted the ds/jmh branch June 19, 2019 23:11
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.

Add JMH benchmarks

4 participants

@schlosna@wenhoujx@carterkozak@iamdanfox