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

Use stack depth to do snapshot assignment #6868

Merged
merged 3 commits into from
Apr 4, 2024

Conversation

jpbempel
Copy link
Member

@jpbempel jpbempel commented Apr 2, 2024

What Does This Do

Instead of relying solely on matching class and method name for snapshot assignment on exception debugging we are using the stack depth of the snapshot of the current frame. It allows to support recursive calls

Motivation

Additional Notes

Jira ticket: DEBUG-2068

Instead of relying solely on matching class and method name for
snapshot assignment on exception debugging we are using the stack
depth of the snapshot of the current frame. It allows to support
recursive calls
@jpbempel jpbempel added tag: no release notes Changes to exclude from release notes comp: debugger Dynamic Instrumentation labels Apr 2, 2024
@jpbempel jpbempel requested a review from a team as a code owner April 2, 2024 16:02
@jpbempel jpbempel requested review from ojung and removed request for a team April 2, 2024 16:02
@pr-commenter
Copy link

pr-commenter bot commented Apr 2, 2024

Benchmarks

Startup

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
git_branch master jpbempel/stack-depth-assignment
git_commit_date 1712231010 1712221105
git_commit_sha 386364a 34c20c0
release_version 1.33.0-SNAPSHOT~386364a9c1 1.32.0-SNAPSHOT~34c20c0090
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1712235131 1712235131
ci_job_id 477730859 477730859
ci_pipeline_id 31432632 31432632
cpu_model Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
module Agent Agent
parent None None
variant iast iast

Summary

Found 2 performance improvements and 2 performance regressions! Performance is the same for 42 metrics, 17 unstable metrics.

scenario Δ mean execution_time candidate mean execution_time baseline mean execution_time
scenario:startup:insecure-bank:tracing:GlobalTracer better
[-13.772ms; -6.230ms] or [-4.444%; -2.010%]
299.893ms 309.894ms
scenario:startup:petclinic:appsec:AppSec worse
[+4.695ms; +8.038ms] or [+3.148%; +5.390%]
155.488ms 149.121ms
scenario:startup:petclinic:appsec:IAST worse
[+436.134µs; +1403.406µs] or [+2.332%; +7.503%]
19.623ms 18.704ms
scenario:startup:petclinic:tracing:GlobalTracer better
[-11.670ms; -9.509ms] or [-3.773%; -3.074%]
298.734ms 309.324ms
Startup time reports for insecure-bank
gantt
    title insecure-bank - global startup overhead: candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.077 s) : 0, 1077219
Total [baseline] (8.568 s) : 0, 8568384
Agent [candidate] (1.082 s) : 0, 1082240
Total [candidate] (8.593 s) : 0, 8592622
section iast
Agent [baseline] (1.202 s) : 0, 1201530
Total [baseline] (9.028 s) : 0, 9028320
Agent [candidate] (1.204 s) : 0, 1203798
Total [candidate] (9.078 s) : 0, 9077815
section iast_HARDCODED_SECRET_DISABLED
Agent [baseline] (1.208 s) : 0, 1208069
Total [baseline] (9.051 s) : 0, 9050801
Agent [candidate] (1.211 s) : 0, 1211188
Total [candidate] (9.067 s) : 0, 9067476
section iast_TELEMETRY_OFF
Agent [baseline] (1.198 s) : 0, 1198326
Total [baseline] (9.031 s) : 0, 9030890
Agent [candidate] (1.198 s) : 0, 1198499
Total [candidate] (9.106 s) : 0, 9106427
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.077 s -
Agent iast 1.202 s 124.311 ms (11.5%)
Agent iast_HARDCODED_SECRET_DISABLED 1.208 s 130.849 ms (12.1%)
Agent iast_TELEMETRY_OFF 1.198 s 121.107 ms (11.2%)
Total tracing 8.568 s -
Total iast 9.028 s 459.937 ms (5.4%)
Total iast_HARDCODED_SECRET_DISABLED 9.051 s 482.417 ms (5.6%)
Total iast_TELEMETRY_OFF 9.031 s 462.506 ms (5.4%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.082 s -
Agent iast 1.204 s 121.558 ms (11.2%)
Agent iast_HARDCODED_SECRET_DISABLED 1.211 s 128.948 ms (11.9%)
Agent iast_TELEMETRY_OFF 1.198 s 116.259 ms (10.7%)
Total tracing 8.593 s -
Total iast 9.078 s 485.192 ms (5.6%)
Total iast_HARDCODED_SECRET_DISABLED 9.067 s 474.854 ms (5.5%)
Total iast_TELEMETRY_OFF 9.106 s 513.805 ms (6.0%)
gantt
    title insecure-bank - break down per module: candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (674.973 ms) : 0, 674973
BytebuddyAgent [candidate] (689.398 ms) : 0, 689398
GlobalTracer [baseline] (309.894 ms) : 0, 309894
GlobalTracer [candidate] (299.893 ms) : 0, 299893
AppSec [baseline] (49.669 ms) : 0, 49669
AppSec [candidate] (49.815 ms) : 0, 49815
Remote Config [baseline] (671.218 µs) : 0, 671
Remote Config [candidate] (1.049 ms) : 0, 1049
Telemetry [baseline] (7.651 ms) : 0, 7651
Telemetry [candidate] (7.515 ms) : 0, 7515
section iast
BytebuddyAgent [baseline] (796.289 ms) : 0, 796289
BytebuddyAgent [candidate] (796.545 ms) : 0, 796545
GlobalTracer [baseline] (288.554 ms) : 0, 288554
GlobalTracer [candidate] (290.434 ms) : 0, 290434
AppSec [baseline] (49.726 ms) : 0, 49726
AppSec [candidate] (49.167 ms) : 0, 49167
IAST [baseline] (24.538 ms) : 0, 24538
IAST [candidate] (25.326 ms) : 0, 25326
Remote Config [baseline] (581.632 µs) : 0, 582
Remote Config [candidate] (572.256 µs) : 0, 572
Telemetry [baseline] (7.407 ms) : 0, 7407
Telemetry [candidate] (7.33 ms) : 0, 7330
section iast_HARDCODED_SECRET_DISABLED
BytebuddyAgent [baseline] (800.988 ms) : 0, 800988
BytebuddyAgent [candidate] (802.576 ms) : 0, 802576
GlobalTracer [baseline] (290.228 ms) : 0, 290228
GlobalTracer [candidate] (292.501 ms) : 0, 292501
AppSec [baseline] (50.472 ms) : 0, 50472
AppSec [candidate] (49.3 ms) : 0, 49300
IAST [baseline] (24.471 ms) : 0, 24471
IAST [candidate] (24.858 ms) : 0, 24858
Remote Config [baseline] (594.765 µs) : 0, 595
Remote Config [candidate] (585.753 µs) : 0, 586
Telemetry [baseline] (6.651 ms) : 0, 6651
Telemetry [candidate] (6.675 ms) : 0, 6675
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (794.18 ms) : 0, 794180
BytebuddyAgent [candidate] (793.299 ms) : 0, 793299
GlobalTracer [baseline] (288.513 ms) : 0, 288513
GlobalTracer [candidate] (290.614 ms) : 0, 290614
AppSec [baseline] (51.336 ms) : 0, 51336
AppSec [candidate] (50.827 ms) : 0, 50827
IAST [baseline] (21.865 ms) : 0, 21865
IAST [candidate] (22.346 ms) : 0, 22346
Remote Config [baseline] (609.555 µs) : 0, 610
Remote Config [candidate] (573.302 µs) : 0, 573
Telemetry [baseline] (7.395 ms) : 0, 7395
Telemetry [candidate] (6.519 ms) : 0, 6519
Loading
Startup time reports for petclinic
gantt
    title petclinic - global startup overhead: candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.076 s) : 0, 1075873
Total [baseline] (10.507 s) : 0, 10506859
Agent [candidate] (1.077 s) : 0, 1077341
Total [candidate] (10.48 s) : 0, 10479662
section appsec
Agent [baseline] (1.195 s) : 0, 1195060
Total [baseline] (10.592 s) : 0, 10591973
Agent [candidate] (1.208 s) : 0, 1207834
Total [candidate] (10.564 s) : 0, 10564478
section iast
Agent [baseline] (1.199 s) : 0, 1198649
Total [baseline] (10.781 s) : 0, 10780912
Agent [candidate] (1.202 s) : 0, 1202243
Total [candidate] (10.861 s) : 0, 10860519
section profiling
Agent [baseline] (1.278 s) : 0, 1278444
Total [baseline] (10.669 s) : 0, 10669093
Agent [candidate] (1.272 s) : 0, 1272143
Total [candidate] (10.663 s) : 0, 10663137
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.076 s -
Agent appsec 1.195 s 119.187 ms (11.1%)
Agent iast 1.199 s 122.776 ms (11.4%)
Agent profiling 1.278 s 202.571 ms (18.8%)
Total tracing 10.507 s -
Total appsec 10.592 s 85.114 ms (0.8%)
Total iast 10.781 s 274.052 ms (2.6%)
Total profiling 10.669 s 162.233 ms (1.5%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.077 s -
Agent appsec 1.208 s 130.493 ms (12.1%)
Agent iast 1.202 s 124.902 ms (11.6%)
Agent profiling 1.272 s 194.802 ms (18.1%)
Total tracing 10.48 s -
Total appsec 10.564 s 84.816 ms (0.8%)
Total iast 10.861 s 380.857 ms (3.6%)
Total profiling 10.663 s 183.475 ms (1.8%)
gantt
    title petclinic - break down per module: candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (674.13 ms) : 0, 674130
BytebuddyAgent [candidate] (686.078 ms) : 0, 686078
GlobalTracer [baseline] (309.324 ms) : 0, 309324
GlobalTracer [candidate] (298.734 ms) : 0, 298734
AppSec [baseline] (49.62 ms) : 0, 49620
AppSec [candidate] (49.467 ms) : 0, 49467
Remote Config [baseline] (668.669 µs) : 0, 669
Remote Config [candidate] (1.053 ms) : 0, 1053
Telemetry [baseline] (7.681 ms) : 0, 7681
Telemetry [candidate] (7.528 ms) : 0, 7528
section appsec
BytebuddyAgent [baseline] (694.615 ms) : 0, 694615
BytebuddyAgent [candidate] (696.346 ms) : 0, 696346
GlobalTracer [baseline] (290.958 ms) : 0, 290958
GlobalTracer [candidate] (294.577 ms) : 0, 294577
AppSec [baseline] (149.121 ms) : 0, 149121
AppSec [candidate] (155.488 ms) : 0, 155488
IAST [baseline] (18.704 ms) : 0, 18704
IAST [candidate] (19.623 ms) : 0, 19623
Remote Config [baseline] (603.361 µs) : 0, 603
Remote Config [candidate] (621.111 µs) : 0, 621
Telemetry [baseline] (6.755 ms) : 0, 6755
Telemetry [candidate] (6.899 ms) : 0, 6899
section iast
BytebuddyAgent [baseline] (794.841 ms) : 0, 794841
BytebuddyAgent [candidate] (796.252 ms) : 0, 796252
GlobalTracer [baseline] (288.207 ms) : 0, 288207
GlobalTracer [candidate] (290.107 ms) : 0, 290107
AppSec [baseline] (48.816 ms) : 0, 48816
AppSec [candidate] (49.915 ms) : 0, 49915
IAST [baseline] (24.328 ms) : 0, 24328
IAST [candidate] (24.402 ms) : 0, 24402
Remote Config [baseline] (594.219 µs) : 0, 594
Remote Config [candidate] (585.142 µs) : 0, 585
Telemetry [baseline] (7.412 ms) : 0, 7412
Telemetry [candidate] (6.568 ms) : 0, 6568
section profiling
BytebuddyAgent [baseline] (683.398 ms) : 0, 683398
BytebuddyAgent [candidate] (678.675 ms) : 0, 678675
GlobalTracer [baseline] (383.029 ms) : 0, 383029
GlobalTracer [candidate] (383.187 ms) : 0, 383187
AppSec [baseline] (50.478 ms) : 0, 50478
AppSec [candidate] (49.949 ms) : 0, 49949
Remote Config [baseline] (713.301 µs) : 0, 713
Remote Config [candidate] (812.84 µs) : 0, 813
Telemetry [baseline] (7.546 ms) : 0, 7546
Telemetry [candidate] (7.506 ms) : 0, 7506
ProfilingAgent [baseline] (96.508 ms) : 0, 96508
ProfilingAgent [candidate] (95.612 ms) : 0, 95612
Profiling [baseline] (96.535 ms) : 0, 96535
Profiling [candidate] (95.636 ms) : 0, 95636
Loading

Load

Request duration reports for insecure-bank
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1
    dateFormat X
    axisFormat %s
section baseline
no_agent (379.175 µs) : 359, 399
.   : milestone, 379,
iast (485.677 µs) : 465, 507
.   : milestone, 486,
iast_FULL (542.58 µs) : 522, 563
.   : milestone, 543,
iast_GLOBAL (511.136 µs) : 489, 533
.   : milestone, 511,
iast_HARDCODED_SECRET_DISABLED (483.346 µs) : 462, 505
.   : milestone, 483,
iast_INACTIVE (451.435 µs) : 431, 472
.   : milestone, 451,
iast_TELEMETRY_OFF (475.926 µs) : 455, 497
.   : milestone, 476,
tracing (451.315 µs) : 430, 472
.   : milestone, 451,
section candidate
no_agent (382.771 µs) : 363, 403
.   : milestone, 383,
iast (480.889 µs) : 460, 501
.   : milestone, 481,
iast_FULL (549.958 µs) : 529, 571
.   : milestone, 550,
iast_GLOBAL (509.284 µs) : 487, 532
.   : milestone, 509,
iast_HARDCODED_SECRET_DISABLED (479.577 µs) : 459, 500
.   : milestone, 480,
iast_INACTIVE (454.166 µs) : 433, 475
.   : milestone, 454,
iast_TELEMETRY_OFF (479.018 µs) : 458, 500
.   : milestone, 479,
tracing (452.276 µs) : 431, 473
.   : milestone, 452,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 379.175 µs [359.224 µs, 399.126 µs] -
iast 485.677 µs [464.521 µs, 506.833 µs] 106.502 µs (28.1%)
iast_FULL 542.58 µs [521.844 µs, 563.317 µs] 163.405 µs (43.1%)
iast_GLOBAL 511.136 µs [489.015 µs, 533.256 µs] 131.961 µs (34.8%)
iast_HARDCODED_SECRET_DISABLED 483.346 µs [462.088 µs, 504.604 µs] 104.171 µs (27.5%)
iast_INACTIVE 451.435 µs [430.899 µs, 471.972 µs] 72.26 µs (19.1%)
iast_TELEMETRY_OFF 475.926 µs [454.8 µs, 497.051 µs] 96.75 µs (25.5%)
tracing 451.315 µs [430.466 µs, 472.164 µs] 72.14 µs (19.0%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 382.771 µs [362.768 µs, 402.774 µs] -
iast 480.889 µs [460.297 µs, 501.482 µs] 98.118 µs (25.6%)
iast_FULL 549.958 µs [529.266 µs, 570.65 µs] 167.187 µs (43.7%)
iast_GLOBAL 509.284 µs [486.704 µs, 531.865 µs] 126.514 µs (33.1%)
iast_HARDCODED_SECRET_DISABLED 479.577 µs [459.077 µs, 500.076 µs] 96.806 µs (25.3%)
iast_INACTIVE 454.166 µs [433.336 µs, 474.997 µs] 71.395 µs (18.7%)
iast_TELEMETRY_OFF 479.018 µs [458.347 µs, 499.689 µs] 96.247 µs (25.1%)
tracing 452.276 µs [431.403 µs, 473.15 µs] 69.506 µs (18.2%)
Request duration reports for petclinic
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~34c20c0090, baseline=1.33.0-SNAPSHOT~386364a9c1
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.354 ms) : 1336, 1373
.   : milestone, 1354,
appsec (1.726 ms) : 1701, 1751
.   : milestone, 1726,
iast (1.496 ms) : 1473, 1519
.   : milestone, 1496,
profiling (1.54 ms) : 1514, 1566
.   : milestone, 1540,
tracing (1.48 ms) : 1456, 1505
.   : milestone, 1480,
section candidate
no_agent (1.363 ms) : 1343, 1382
.   : milestone, 1363,
appsec (1.736 ms) : 1711, 1761
.   : milestone, 1736,
iast (1.499 ms) : 1476, 1521
.   : milestone, 1499,
profiling (1.516 ms) : 1490, 1542
.   : milestone, 1516,
tracing (1.492 ms) : 1467, 1516
.   : milestone, 1492,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.354 ms [1.336 ms, 1.373 ms] -
appsec 1.726 ms [1.701 ms, 1.751 ms] 371.698 µs (27.4%)
iast 1.496 ms [1.473 ms, 1.519 ms] 141.237 µs (10.4%)
profiling 1.54 ms [1.514 ms, 1.566 ms] 185.382 µs (13.7%)
tracing 1.48 ms [1.456 ms, 1.505 ms] 125.708 µs (9.3%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.363 ms [1.343 ms, 1.382 ms] -
appsec 1.736 ms [1.711 ms, 1.761 ms] 372.979 µs (27.4%)
iast 1.499 ms [1.476 ms, 1.521 ms] 135.941 µs (10.0%)
profiling 1.516 ms [1.49 ms, 1.542 ms] 153.534 µs (11.3%)
tracing 1.492 ms [1.467 ms, 1.516 ms] 128.999 µs (9.5%)

Copy link
Contributor

@shatzi shatzi left a comment

Choose a reason for hiding this comment

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

Awesome stuff

&& !innerTrace[currentIdx].getClassName().equals(className)
&& !innerTrace[currentIdx].getMethodName().equals(methodName)) {
currentIdx++;
currentIdx = innerTrace.length - snapshot.getStack().size();
Copy link
Contributor

Choose a reason for hiding this comment

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

CurrenntIdx can be inner to the loop now

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

@@ -124,6 +121,18 @@ private static void processSnapshotsAndSetTags(
}
}

private static boolean sanityCheckSnapshotAssignment(
Copy link
Contributor

Choose a reason for hiding this comment

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

How good that works on your testing?

Copy link
Member Author

Choose a reason for hiding this comment

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

never see the warning so far

mapping[i] = j;
int count = currentTrace.length;
int idx = currentIdx;
while (count > 0) {
Copy link
Contributor

Choose a reason for hiding this comment

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

Not sure I understand this logic.
Why we have two loops here?
Why do we need to do %?

Can you explain the edge cases we are trying to solve here?

Copy link
Member Author

Choose a reason for hiding this comment

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

I need to scan the whole flattened stacktrace (currentTrace) but the first snapshot can match near the end of the currentTrace, and once I match on frame I want to scan on next one, but because of the layout of the flattened one I need to warp around to try to match lower frames.

example:

	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:626)
	at java.lang.Thread.run(Thread.java:750)
Caused by: java.lang.RuntimeException: oops fibo
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:218)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.fiboException(VetController.java:220)
	at org.springframework.samples.petclinic.vet.VetController.showVetList(VetController.java:182)
	... 53 more

My first frame will be fiboException(VetController.java:218) then down to ... 53 more then I need to restart from the beginning processRequest(FrameworkServlet.java:1014) and down again and here this is still a simple case we may have multiple nested exceptions

Copy link
Member Author

Choose a reason for hiding this comment

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

I have added some comments in the code

@jpbempel jpbempel merged commit 734e3c5 into master Apr 4, 2024
77 checks passed
@jpbempel jpbempel deleted the jpbempel/stack-depth-assignment branch April 4, 2024 12:54
@github-actions github-actions bot added this to the 1.33.0 milestone Apr 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp: debugger Dynamic Instrumentation tag: no release notes Changes to exclude from release notes
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants