Skip to content

JFR based profiling context#6261

Merged
richardstartin merged 4 commits into
masterfrom
rgs/jfr-trace-context
Nov 29, 2023
Merged

JFR based profiling context#6261
richardstartin merged 4 commits into
masterfrom
rgs/jfr-trace-context

Conversation

@richardstartin
Copy link
Copy Markdown
Contributor

@richardstartin richardstartin commented Nov 22, 2023 •
edited
Loading

What Does This Do

This emits JFR events spanning each scope activation. It does this by introducing an interface called Stateful which is an AutoCloseable which hides the checked exception, and the scope manager creates this Stateful when it creates scopes, and the scopes ensure the Stateful is closed when the scope is closed. When a scope becomes the top of the scope stack again, it passes the context to the Stateful::activate method, which the Stateful implementation is free to use or ignore. These interactions are enough to generalise over the existing ddprof-based context integration, and a new one which is essentially identical to the first incarnation of scope events. This refactoring moves most of the profiling logic out of the scope stack, except for the notifications of when the stack becomes empty/non-empty.

A new implementation of ProfilingContextIntegration is registered when a feature flag is set and ddprof is disabled, is not supported on the current OS, or cannot be loaded for other reasons. This implementation simply produces a TimelineEvent when a scope is started, does nothing when a scope is reactivated, and commits the event when the scope is closed if enough time has elapsed since its creation. Dealing with stack of overlapping events is handled in our backend.

Motivation

This is required for filtering down to trace level in the timeline when ddprof is not in use, which widens support for the trace level timeline.

Additional Notes

Jira ticket: PROF-8687

@pr-commenter
Copy link
Copy Markdown

pr-commenter Bot commented Nov 22, 2023 •
edited
Loading

Benchmarks

Startup

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
git_branch master rgs/jfr-trace-context
git_commit_date 1700735892 1700740147
git_commit_sha 48850c7 d4f2456
release_version 1.25.0-SNAPSHOT~48850c78e8 1.25.0-SNAPSHOT~d4f24564dc
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1700742833 1700742833
ci_job_id 375578880 375578880
ci_pipeline_id 23754245 23754245
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 0 performance improvements and 0 performance regressions! Performance is the same for 45 metrics, 9 unstable metrics.

Startup time reports for petclinic 
gantt
    title petclinic - global startup overhead: candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.03 s) : 0, 1030398
Total [baseline] (9.312 s) : 0, 9311775
Agent [candidate] (1.034 s) : 0, 1033616
Total [candidate] (9.31 s) : 0, 9309587
section appsec
Agent [baseline] (1.118 s) : 0, 1117679
Total [baseline] (9.367 s) : 0, 9366679
Agent [candidate] (1.12 s) : 0, 1120328
Total [candidate] (9.518 s) : 0, 9518066
section iast
Agent [baseline] (1.147 s) : 0, 1147489
Total [baseline] (9.497 s) : 0, 9496897
Agent [candidate] (1.15 s) : 0, 1150455
Total [candidate] (9.485 s) : 0, 9485084
section profiling
Agent [baseline] (1.217 s) : 0, 1217048
Total [baseline] (9.574 s) : 0, 9574487
Agent [candidate] (1.222 s) : 0, 1221867
Total [candidate] (9.671 s) : 0, 9671274
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.03 s -
Agent appsec 1.118 s 87.28 ms (8.5%)
Agent iast 1.147 s 117.091 ms (11.4%)
Agent profiling 1.217 s 186.649 ms (18.1%)
Total tracing 9.312 s -
Total appsec 9.367 s 54.905 ms (0.6%)
Total iast 9.497 s 185.122 ms (2.0%)
Total profiling 9.574 s 262.712 ms (2.8%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.034 s -
Agent appsec 1.12 s 86.711 ms (8.4%)
Agent iast 1.15 s 116.839 ms (11.3%)
Agent profiling 1.222 s 188.251 ms (18.2%)
Total tracing 9.31 s -
Total appsec 9.518 s 208.479 ms (2.2%)
Total iast 9.485 s 175.497 ms (1.9%)
Total profiling 9.671 s 361.687 ms (3.9%) 
gantt
    title petclinic - break down per module: candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (643.336 ms) : 0, 643336
BytebuddyAgent [candidate] (644.271 ms) : 0, 644271
GlobalTracer [baseline] (296.656 ms) : 0, 296656
GlobalTracer [candidate] (298.942 ms) : 0, 298942
AppSec [baseline] (48.218 ms) : 0, 48218
AppSec [candidate] (48.233 ms) : 0, 48233
Remote Config [baseline] (676.263 µs) : 0, 676
Remote Config [candidate] (672.793 µs) : 0, 673
Telemetry [baseline] (7.273 ms) : 0, 7273
Telemetry [candidate] (7.227 ms) : 0, 7227
section appsec
BytebuddyAgent [baseline] (642.813 ms) : 0, 642813
BytebuddyAgent [candidate] (643.624 ms) : 0, 643624
GlobalTracer [baseline] (296.907 ms) : 0, 296907
GlobalTracer [candidate] (298.369 ms) : 0, 298369
AppSec [baseline] (136.308 ms) : 0, 136308
AppSec [candidate] (136.725 ms) : 0, 136725
Remote Config [baseline] (652.989 µs) : 0, 653
Remote Config [candidate] (641.861 µs) : 0, 642
Telemetry [baseline] (6.743 ms) : 0, 6743
Telemetry [candidate] (6.718 ms) : 0, 6718
section iast
BytebuddyAgent [baseline] (762.171 ms) : 0, 762171
BytebuddyAgent [candidate] (764.572 ms) : 0, 764572
GlobalTracer [baseline] (276.939 ms) : 0, 276939
GlobalTracer [candidate] (278.63 ms) : 0, 278630
AppSec [baseline] (50.446 ms) : 0, 50446
AppSec [candidate] (50.571 ms) : 0, 50571
Remote Config [baseline] (561.94 µs) : 0, 562
Remote Config [candidate] (572.35 µs) : 0, 572
Telemetry [baseline] (8.591 ms) : 0, 8591
Telemetry [candidate] (7.837 ms) : 0, 7837
IAST [baseline] (14.592 ms) : 0, 14592
IAST [candidate] (14.014 ms) : 0, 14014
section profiling
BytebuddyAgent [baseline] (652.225 ms) : 0, 652225
BytebuddyAgent [candidate] (654.558 ms) : 0, 654558
GlobalTracer [baseline] (366.907 ms) : 0, 366907
GlobalTracer [candidate] (368.371 ms) : 0, 368371
AppSec [baseline] (48.374 ms) : 0, 48374
AppSec [candidate] (48.417 ms) : 0, 48417
Remote Config [baseline] (706.374 µs) : 0, 706
Remote Config [candidate] (699.342 µs) : 0, 699
Telemetry [baseline] (7.336 ms) : 0, 7336
Telemetry [candidate] (7.417 ms) : 0, 7417
ProfilingAgent [baseline] (87.658 ms) : 0, 87658
ProfilingAgent [candidate] (88.35 ms) : 0, 88350
Profiling [baseline] (87.681 ms) : 0, 87681
Profiling [candidate] (88.373 ms) : 0, 88373
Loading
Startup time reports for insecure-bank 
gantt
    title insecure-bank - global startup overhead: candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.036 s) : 0, 1036011
Total [baseline] (8.665 s) : 0, 8664585
Agent [candidate] (1.038 s) : 0, 1037887
Total [candidate] (8.683 s) : 0, 8683103
section iast
Agent [baseline] (1.145 s) : 0, 1145100
Total [baseline] (9.194 s) : 0, 9194156
Agent [candidate] (1.152 s) : 0, 1151582
Total [candidate] (9.23 s) : 0, 9230280
section iast_TELEMETRY_OFF
Agent [baseline] (1.138 s) : 0, 1138273
Total [baseline] (9.18 s) : 0, 9180097
Agent [candidate] (1.144 s) : 0, 1143575
Total [candidate] (9.217 s) : 0, 9216844
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.036 s -
Agent iast 1.145 s 109.09 ms (10.5%)
Agent iast_TELEMETRY_OFF 1.138 s 102.262 ms (9.9%)
Total tracing 8.665 s -
Total iast 9.194 s 529.571 ms (6.1%)
Total iast_TELEMETRY_OFF 9.18 s 515.512 ms (5.9%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.038 s -
Agent iast 1.152 s 113.695 ms (11.0%)
Agent iast_TELEMETRY_OFF 1.144 s 105.687 ms (10.2%)
Total tracing 8.683 s -
Total iast 9.23 s 547.178 ms (6.3%)
Total iast_TELEMETRY_OFF 9.217 s 533.741 ms (6.1%) 
gantt
    title insecure-bank - break down per module: candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (646.746 ms) : 0, 646746
BytebuddyAgent [candidate] (647.315 ms) : 0, 647315
GlobalTracer [baseline] (298.427 ms) : 0, 298427
GlobalTracer [candidate] (299.701 ms) : 0, 299701
AppSec [baseline] (48.344 ms) : 0, 48344
AppSec [candidate] (48.412 ms) : 0, 48412
Remote Config [baseline] (672.855 µs) : 0, 673
Remote Config [candidate] (674.597 µs) : 0, 675
Telemetry [baseline] (7.366 ms) : 0, 7366
Telemetry [candidate] (7.278 ms) : 0, 7278
section iast
BytebuddyAgent [baseline] (760.512 ms) : 0, 760512
BytebuddyAgent [candidate] (764.59 ms) : 0, 764590
GlobalTracer [baseline] (276.475 ms) : 0, 276475
GlobalTracer [candidate] (278.825 ms) : 0, 278825
AppSec [baseline] (50.837 ms) : 0, 50837
AppSec [candidate] (51.259 ms) : 0, 51259
IAST [baseline] (14.686 ms) : 0, 14686
IAST [candidate] (14.05 ms) : 0, 14050
Remote Config [baseline] (560.103 µs) : 0, 560
Remote Config [candidate] (570.952 µs) : 0, 571
Telemetry [baseline] (7.919 ms) : 0, 7919
Telemetry [candidate] (7.982 ms) : 0, 7982
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (754.492 ms) : 0, 754492
BytebuddyAgent [candidate] (757.415 ms) : 0, 757415
GlobalTracer [baseline] (276.941 ms) : 0, 276941
GlobalTracer [candidate] (278.576 ms) : 0, 278576
AppSec [baseline] (46.461 ms) : 0, 46461
AppSec [candidate] (46.593 ms) : 0, 46593
IAST [baseline] (17.219 ms) : 0, 17219
IAST [candidate] (16.872 ms) : 0, 16872
Remote Config [baseline] (563.586 µs) : 0, 564
Remote Config [candidate] (598.397 µs) : 0, 598
Telemetry [baseline] (8.383 ms) : 0, 8383
Telemetry [candidate] (9.278 ms) : 0, 9278
Loading

Load

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
end_time 2023-11-23T12:13:10 2023-11-23T12:29:41
git_branch master rgs/jfr-trace-context
git_commit_date 1700735892 1700740147
git_commit_sha 48850c7 d4f2456
release_version 1.25.0-SNAPSHOT~48850c78e8 1.25.0-SNAPSHOT~d4f24564dc
start_time 2023-11-23T12:12:57 2023-11-23T12:29:28
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1700742833 1700742833
ci_job_id 375578880 375578880
ci_pipeline_id 23754245 23754245
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 8 metrics, 14 unstable metrics.

Request duration reports for petclinic 
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.374 ms) : 1355, 1394
.   : milestone, 1374,
appsec (1.756 ms) : 1731, 1782
.   : milestone, 1756,
iast (1.529 ms) : 1505, 1553
.   : milestone, 1529,
profiling (1.507 ms) : 1481, 1533
.   : milestone, 1507,
tracing (1.509 ms) : 1484, 1534
.   : milestone, 1509,
section candidate
no_agent (1.348 ms) : 1328, 1367
.   : milestone, 1348,
appsec (1.76 ms) : 1735, 1785
.   : milestone, 1760,
iast (1.515 ms) : 1491, 1539
.   : milestone, 1515,
profiling (1.511 ms) : 1486, 1536
.   : milestone, 1511,
tracing (1.521 ms) : 1496, 1547
.   : milestone, 1521,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.374 ms [1.355 ms, 1.394 ms] -
appsec 1.756 ms [1.731 ms, 1.782 ms] 381.829 µs (27.8%)
iast 1.529 ms [1.505 ms, 1.553 ms] 154.571 µs (11.2%)
profiling 1.507 ms [1.481 ms, 1.533 ms] 132.383 µs (9.6%)
tracing 1.509 ms [1.484 ms, 1.534 ms] 134.225 µs (9.8%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.348 ms [1.328 ms, 1.367 ms] -
appsec 1.76 ms [1.735 ms, 1.785 ms] 412.323 µs (30.6%)
iast 1.515 ms [1.491 ms, 1.539 ms] 167.52 µs (12.4%)
profiling 1.511 ms [1.486 ms, 1.536 ms] 163.327 µs (12.1%)
tracing 1.521 ms [1.496 ms, 1.547 ms] 173.614 µs (12.9%)
Request duration reports for insecure-bank 
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.25.0-SNAPSHOT~d4f24564dc, baseline=1.25.0-SNAPSHOT~48850c78e8
    dateFormat X
    axisFormat %s
section baseline
no_agent (362.907 µs) : 342, 384
.   : milestone, 363,
iast (469.146 µs) : 448, 490
.   : milestone, 469,
iast_FULL (529.326 µs) : 509, 550
.   : milestone, 529,
iast_INACTIVE (441.569 µs) : 420, 463
.   : milestone, 442,
iast_TELEMETRY_OFF (469.365 µs) : 449, 490
.   : milestone, 469,
tracing (441.186 µs) : 420, 463
.   : milestone, 441,
section candidate
no_agent (366.349 µs) : 344, 389
.   : milestone, 366,
iast (474.464 µs) : 454, 495
.   : milestone, 474,
iast_FULL (531.164 µs) : 511, 552
.   : milestone, 531,
iast_INACTIVE (441.649 µs) : 421, 462
.   : milestone, 442,
iast_TELEMETRY_OFF (467.321 µs) : 446, 488
.   : milestone, 467,
tracing (438.355 µs) : 418, 459
.   : milestone, 438,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 362.907 µs [341.814 µs, 384.001 µs] -
iast 469.146 µs [448.396 µs, 489.895 µs] 106.238 µs (29.3%)
iast_FULL 529.326 µs [508.873 µs, 549.778 µs] 166.418 µs (45.9%)
iast_INACTIVE 441.569 µs [420.334 µs, 462.804 µs] 78.661 µs (21.7%)
iast_TELEMETRY_OFF 469.365 µs [448.684 µs, 490.046 µs] 106.458 µs (29.3%)
tracing 441.186 µs [419.575 µs, 462.797 µs] 78.279 µs (21.6%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 366.349 µs [343.738 µs, 388.959 µs] -
iast 474.464 µs [453.966 µs, 494.962 µs] 108.116 µs (29.5%)
iast_FULL 531.164 µs [510.702 µs, 551.625 µs] 164.815 µs (45.0%)
iast_INACTIVE 441.649 µs [420.9 µs, 462.399 µs] 75.301 µs (20.6%)
iast_TELEMETRY_OFF 467.321 µs [446.297 µs, 488.345 µs] 100.973 µs (27.6%)
tracing 438.355 µs [417.511 µs, 459.198 µs] 72.006 µs (19.7%)

@richardstartin richardstartin force-pushed the rgs/jfr-trace-context branch 4 times, most recently from 51c7ca5 to 1afead4 Compare November 22, 2023 17:43
@richardstartin richardstartin marked this pull request as ready for review November 22, 2023 17:54
@richardstartin richardstartin requested review from a team as code owners November 22, 2023 17:54
@richardstartin richardstartin marked this pull request as draft November 22, 2023 18:25
@richardstartin richardstartin removed request for a team, am312 and ygree November 22, 2023 18:26
@richardstartin richardstartin marked this pull request as ready for review November 23, 2023 13:04
@richardstartin richardstartin requested review from a team, dougqh and mcculls November 23, 2023 13:05
@richardstartin richardstartin merged commit f6f3414 into master Nov 29, 2023
@richardstartin richardstartin deleted the rgs/jfr-trace-context branch November 29, 2023 18:22
@github-actions github-actions Bot added this to the 1.25.0 milestone Nov 29, 2023
@bm1549 bm1549 added the comp: profiling Profiling label Dec 5, 2023
@richardstartin richardstartin mentioned this pull request Mar 22, 2024
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@jbachorik jbachorik jbachorik approved these changes

@mcculls mcculls Awaiting requested review from mcculls mcculls is a code owner automatically assigned from DataDog/apm-java

@dougqh dougqh Awaiting requested review from dougqh dougqh is a code owner automatically assigned from DataDog/apm-java

Assignees

No one assigned

Labels

comp: profiling Profiling

Projects

None yet

Milestone

1.25.0

Development

Successfully merging this pull request may close these issues.

3 participants

@richardstartin @jbachorik @bm1549