Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix mixing log/span decoration probes #7246

Merged
merged 2 commits into from
Jul 9, 2024
Merged

Conversation

jpbempel
Copy link
Member

@jpbempel jpbempel commented Jun 26, 2024

What Does This Do

On same location, if we have different probes like log or span decoration probe with different characteristics (capture, snapshot, evaluateAt,...), instrumentation needs the correct definition to apply
the shared CapturedContextInstrumentor.
We are creating a synthetic definition for applying instrumentation and merging all characteristics required for instrumentation.

Motivation

Additional Notes

Jira ticket: DEBUG-2498

On same location, if we have different probes like log or span
decoration probe with different characteristics (capture, snapshot,
evaluateAt,...), instrumentation needs the correct definition to apply
 the shared CapturedContextInstrumentor.
We are creating a synthetic definition for applying instrumentation
and merging all characteristics required for instrumentation.
@jpbempel jpbempel requested a review from a team as a code owner June 26, 2024 17:38
@jpbempel jpbempel requested review from shatzi and removed request for a team June 26, 2024 17:38
@pr-commenter
Copy link

pr-commenter bot commented Jun 26, 2024

Benchmarks

Startup

Load

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
end_time 2024-07-09T12:16:50 2024-07-09T12:23:37
git_branch master jpbempel/fix-mixing-log-span
git_commit_date 1720518949 1720526245
git_commit_sha 5ab86d2 ebff4fa
release_version 1.38.0-SNAPSHOT~5ab86d20e4 1.36.0-SNAPSHOT~ebff4fad7a
start_time 2024-07-09T12:16:37 2024-07-09T12:23:24
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1720528160 1720528160
ci_job_id 566444064 566444064
ci_pipeline_id 38691656 38691656
cpu_model Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
variant iast iast

Summary

Found 0 performance improvements and 0 performance regressions! Performance is the same for 12 metrics, 16 unstable metrics.

Request duration reports for petclinic
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.36.0-SNAPSHOT~ebff4fad7a, baseline=1.38.0-SNAPSHOT~5ab86d20e4
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.336 ms) : 1317, 1355
.   : milestone, 1336,
appsec (1.726 ms) : 1703, 1749
.   : milestone, 1726,
appsec_no_iast (1.712 ms) : 1687, 1736
.   : milestone, 1712,
iast (1.465 ms) : 1443, 1488
.   : milestone, 1465,
profiling (1.48 ms) : 1455, 1504
.   : milestone, 1480,
tracing (1.449 ms) : 1425, 1474
.   : milestone, 1449,
section candidate
no_agent (1.335 ms) : 1316, 1354
.   : milestone, 1335,
appsec (1.706 ms) : 1683, 1730
.   : milestone, 1706,
appsec_no_iast (1.72 ms) : 1696, 1744
.   : milestone, 1720,
iast (1.46 ms) : 1437, 1483
.   : milestone, 1460,
profiling (1.528 ms) : 1504, 1553
.   : milestone, 1528,
tracing (1.459 ms) : 1435, 1482
.   : milestone, 1459,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.336 ms [1.317 ms, 1.355 ms] -
appsec 1.726 ms [1.703 ms, 1.749 ms] 389.457 µs (29.1%)
appsec_no_iast 1.712 ms [1.687 ms, 1.736 ms] 375.564 µs (28.1%)
iast 1.465 ms [1.443 ms, 1.488 ms] 129.114 µs (9.7%)
profiling 1.48 ms [1.455 ms, 1.504 ms] 143.405 µs (10.7%)
tracing 1.449 ms [1.425 ms, 1.474 ms] 113.214 µs (8.5%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.335 ms [1.316 ms, 1.354 ms] -
appsec 1.706 ms [1.683 ms, 1.73 ms] 370.995 µs (27.8%)
appsec_no_iast 1.72 ms [1.696 ms, 1.744 ms] 385.156 µs (28.8%)
iast 1.46 ms [1.437 ms, 1.483 ms] 124.609 µs (9.3%)
profiling 1.528 ms [1.504 ms, 1.553 ms] 193.269 µs (14.5%)
tracing 1.459 ms [1.435 ms, 1.482 ms] 123.498 µs (9.3%)
Request duration reports for insecure-bank
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.36.0-SNAPSHOT~ebff4fad7a, baseline=1.38.0-SNAPSHOT~5ab86d20e4
    dateFormat X
    axisFormat %s
section baseline
no_agent (361.67 µs) : 342, 381
.   : milestone, 362,
iast (469.84 µs) : 449, 491
.   : milestone, 470,
iast_FULL (544.224 µs) : 523, 565
.   : milestone, 544,
iast_GLOBAL (502.851 µs) : 482, 524
.   : milestone, 503,
iast_HARDCODED_SECRET_DISABLED (479.767 µs) : 458, 501
.   : milestone, 480,
iast_INACTIVE (456.26 µs) : 435, 477
.   : milestone, 456,
iast_TELEMETRY_OFF (463.412 µs) : 443, 484
.   : milestone, 463,
tracing (441.332 µs) : 420, 463
.   : milestone, 441,
section candidate
no_agent (362.578 µs) : 343, 382
.   : milestone, 363,
iast (472.758 µs) : 452, 494
.   : milestone, 473,
iast_FULL (541.885 µs) : 521, 563
.   : milestone, 542,
iast_GLOBAL (504.852 µs) : 483, 527
.   : milestone, 505,
iast_HARDCODED_SECRET_DISABLED (472.337 µs) : 451, 493
.   : milestone, 472,
iast_INACTIVE (447.479 µs) : 426, 469
.   : milestone, 447,
iast_TELEMETRY_OFF (467.238 µs) : 446, 489
.   : milestone, 467,
tracing (437.244 µs) : 416, 459
.   : milestone, 437,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 361.67 µs [342.381 µs, 380.959 µs] -
iast 469.84 µs [448.688 µs, 490.993 µs] 108.17 µs (29.9%)
iast_FULL 544.224 µs [523.374 µs, 565.075 µs] 182.555 µs (50.5%)
iast_GLOBAL 502.851 µs [481.887 µs, 523.815 µs] 141.182 µs (39.0%)
iast_HARDCODED_SECRET_DISABLED 479.767 µs [458.486 µs, 501.049 µs] 118.097 µs (32.7%)
iast_INACTIVE 456.26 µs [435.261 µs, 477.259 µs] 94.59 µs (26.2%)
iast_TELEMETRY_OFF 463.412 µs [442.579 µs, 484.245 µs] 101.742 µs (28.1%)
tracing 441.332 µs [420.107 µs, 462.557 µs] 79.662 µs (22.0%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 362.578 µs [342.851 µs, 382.304 µs] -
iast 472.758 µs [451.621 µs, 493.895 µs] 110.18 µs (30.4%)
iast_FULL 541.885 µs [520.696 µs, 563.073 µs] 179.307 µs (49.5%)
iast_GLOBAL 504.852 µs [482.826 µs, 526.878 µs] 142.274 µs (39.2%)
iast_HARDCODED_SECRET_DISABLED 472.337 µs [451.178 µs, 493.496 µs] 109.76 µs (30.3%)
iast_INACTIVE 447.479 µs [426.134 µs, 468.824 µs] 84.901 µs (23.4%)
iast_TELEMETRY_OFF 467.238 µs [445.86 µs, 488.615 µs] 104.66 µs (28.9%)
tracing 437.244 µs [415.629 µs, 458.858 µs] 74.666 µs (20.6%)

Dacapo

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
git_branch master jpbempel/fix-mixing-log-span
git_commit_date 1720518949 1720526245
git_commit_sha 5ab86d2 ebff4fa
release_version 1.38.0-SNAPSHOT~5ab86d20e4 1.36.0-SNAPSHOT~ebff4fad7a
See matching parameters
Baseline Candidate
application biojava biojava
ci_job_date 1720528655 1720528655
ci_job_id 566444066 566444066
ci_pipeline_id 38691656 38691656
cpu_model Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
variant appsec appsec

Summary

Found 0 performance improvements and 0 performance regressions! Performance is the same for 12 metrics, 0 unstable metrics.

Execution time for biojava
gantt
    title biojava - execution time [CI 0.99] : candidate=1.36.0-SNAPSHOT~ebff4fad7a, baseline=1.38.0-SNAPSHOT~5ab86d20e4
    dateFormat X
    axisFormat %s
section baseline
no_agent (14.936 s) : 14936000, 14936000
.   : milestone, 14936000,
appsec (15.069 s) : 15069000, 15069000
.   : milestone, 15069000,
iast (18.739 s) : 18739000, 18739000
.   : milestone, 18739000,
iast_GLOBAL (18.039 s) : 18039000, 18039000
.   : milestone, 18039000,
profiling (15.52 s) : 15520000, 15520000
.   : milestone, 15520000,
tracing (14.795 s) : 14795000, 14795000
.   : milestone, 14795000,
section candidate
no_agent (15.549 s) : 15549000, 15549000
.   : milestone, 15549000,
appsec (15.13 s) : 15130000, 15130000
.   : milestone, 15130000,
iast (18.877 s) : 18877000, 18877000
.   : milestone, 18877000,
iast_GLOBAL (17.928 s) : 17928000, 17928000
.   : milestone, 17928000,
profiling (15.004 s) : 15004000, 15004000
.   : milestone, 15004000,
tracing (15.161 s) : 15161000, 15161000
.   : milestone, 15161000,
Loading
  • baseline results
Variant Execution Time [CI 0.99] Δ no_agent
no_agent 14.936 s [14.936 s, 14.936 s] -
appsec 15.069 s [15.069 s, 15.069 s] 133.0 ms (0.9%)
iast 18.739 s [18.739 s, 18.739 s] 3.803 s (25.5%)
iast_GLOBAL 18.039 s [18.039 s, 18.039 s] 3.103 s (20.8%)
profiling 15.52 s [15.52 s, 15.52 s] 584.0 ms (3.9%)
tracing 14.795 s [14.795 s, 14.795 s] -141.0 ms (-0.9%)
  • candidate results
Variant Execution Time [CI 0.99] Δ no_agent
no_agent 15.549 s [15.549 s, 15.549 s] -
appsec 15.13 s [15.13 s, 15.13 s] -419.0 ms (-2.7%)
iast 18.877 s [18.877 s, 18.877 s] 3.328 s (21.4%)
iast_GLOBAL 17.928 s [17.928 s, 17.928 s] 2.379 s (15.3%)
profiling 15.004 s [15.004 s, 15.004 s] -545.0 ms (-3.5%)
tracing 15.161 s [15.161 s, 15.161 s] -388.0 ms (-2.5%)
Execution time for tomcat
gantt
    title tomcat - execution time [CI 0.99] : candidate=1.36.0-SNAPSHOT~ebff4fad7a, baseline=1.38.0-SNAPSHOT~5ab86d20e4
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.452 ms) : 1441, 1463
.   : milestone, 1452,
appsec (2.225 ms) : 2190, 2260
.   : milestone, 2225,
iast (1.964 ms) : 1922, 2005
.   : milestone, 1964,
iast_GLOBAL (2.017 ms) : 1973, 2060
.   : milestone, 2017,
profiling (1.86 ms) : 1826, 1894
.   : milestone, 1860,
tracing (1.821 ms) : 1788, 1854
.   : milestone, 1821,
section candidate
no_agent (1.45 ms) : 1439, 1461
.   : milestone, 1450,
appsec (2.203 ms) : 2169, 2236
.   : milestone, 2203,
iast (1.932 ms) : 1892, 1972
.   : milestone, 1932,
iast_GLOBAL (1.983 ms) : 1943, 2023
.   : milestone, 1983,
profiling (1.828 ms) : 1796, 1860
.   : milestone, 1828,
tracing (1.808 ms) : 1778, 1839
.   : milestone, 1808,
Loading
  • baseline results
Variant Execution Time [CI 0.99] Δ no_agent
no_agent 1.452 ms [1.441 ms, 1.463 ms] -
appsec 2.225 ms [2.19 ms, 2.26 ms] 773.474 µs (53.3%)
iast 1.964 ms [1.922 ms, 2.005 ms] 511.944 µs (35.3%)
iast_GLOBAL 2.017 ms [1.973 ms, 2.06 ms] 564.689 µs (38.9%)
profiling 1.86 ms [1.826 ms, 1.894 ms] 408.279 µs (28.1%)
tracing 1.821 ms [1.788 ms, 1.854 ms] 369.269 µs (25.4%)
  • candidate results
Variant Execution Time [CI 0.99] Δ no_agent
no_agent 1.45 ms [1.439 ms, 1.461 ms] -
appsec 2.203 ms [2.169 ms, 2.236 ms] 752.602 µs (51.9%)
iast 1.932 ms [1.892 ms, 1.972 ms] 482.075 µs (33.2%)
iast_GLOBAL 1.983 ms [1.943 ms, 2.023 ms] 532.572 µs (36.7%)
profiling 1.828 ms [1.796 ms, 1.86 ms] 377.979 µs (26.1%)
tracing 1.808 ms [1.778 ms, 1.839 ms] 358.476 µs (24.7%)

capture = mergeCapture(capture, logProbe.getCapture());
}
if (definition.getEvaluateAt() == MethodLocation.ENTRY
|| definition.getEvaluateAt() == MethodLocation.DEFAULT) {
Copy link
Contributor

Choose a reason for hiding this comment

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

why we overwrite EXIT with default?

Copy link
Contributor

Choose a reason for hiding this comment

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

I think there should be a priority here.. if there are two probes one with DEFAULT and one with ENTRY.. the order of us going over the probe would have determine which one wins.

Does this even matter?

Copy link
Member Author

Choose a reason for hiding this comment

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

DEFAULT == ENTRY from the beginning.
The fact that by default, UI put EXIT is independent of what we are doing here.

.build();
}

private LogProbe.Sampling mergeSampling(
Copy link
Contributor

Choose a reason for hiding this comment

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

why do we care about merge the sampling?

I thought we rate-limit each probe independently.. do we use the sampling of the reference definition?

Copy link
Member Author

Choose a reason for hiding this comment

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

left over. this method is not called. removed

}

<T extends ProbeDefinition> T createMock(
Class<T> clazz, List<ProbeDefinition> invocationOrder, String id) {
ProbeDefinition mock = mock(clazz);
doAnswer(
invocation -> {
invocationOrder.add(mock);
// invocationOrder.add(mock);
Copy link
Contributor

Choose a reason for hiding this comment

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

remove?

Copy link
Member Author

Choose a reason for hiding this comment

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

done

.where(CLASS_NAME, "process")
.captureSnapshot(true)
.sampling(10.0)
.capture(5, 200, 200, 30)
Copy link
Contributor

Choose a reason for hiding this comment

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

do we want to test that we merge the sampling and captures limit correctly?

Copy link
Member Author

Choose a reason for hiding this comment

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

added test

add test for merging capture limits
@jpbempel jpbempel merged commit 3de43de into master Jul 9, 2024
82 checks passed
@jpbempel jpbempel deleted the jpbempel/fix-mixing-log-span branch July 9, 2024 13:55
@github-actions github-actions bot added this to the 1.38.0 milestone Jul 9, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp: debugger Dynamic Instrumentation
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants