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.

Sign up for GitHub

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

Jump to bottom

Enable queue time tracing by default #6833

Merged
merged 1 commit into from Mar 21, 2024
Merged

Enable queue time tracing by default #6833

merged 1 commit into from Mar 21, 2024

Conversation

richardstartin
Copy link
Member

What Does This Do

Enables a feature which records the amount of time spent queueing in various thread pool mechanisms. This feature is conservative and will only report waits longer than 50ms.

Motivation

Additional Notes

Jira ticket: [PROJ-IDENT]

@richardstartin richardstartin requested review from a team as code owners March 21, 2024 14:16
@pr-commenter
Copy link

pr-commenter bot commented Mar 21, 2024

Benchmarks

Startup

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
git_branch master rgs/ga-queue-time
git_commit_date 1711026257 1711030488
git_commit_sha 45ff2b9 387b718
release_version 1.32.0-SNAPSHOT~45ff2b9808 1.32.0-SNAPSHOT~387b7187e6
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1711033655 1711033655
ci_job_id 465899816 465899816
ci_pipeline_id 30546971 30546971
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 50 metrics, 13 unstable metrics.

Startup time reports for petclinic 
gantt
    title petclinic - global startup overhead: candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.076 s) : 0, 1076287
Total [baseline] (9.117 s) : 0, 9116827
Agent [candidate] (1.078 s) : 0, 1077947
Total [candidate] (9.113 s) : 0, 9112683
section appsec
Agent [baseline] (1.211 s) : 0, 1211360
Total [baseline] (9.351 s) : 0, 9351265
Agent [candidate] (1.205 s) : 0, 1204747
Total [candidate] (9.307 s) : 0, 9306921
section iast
Agent [baseline] (1.221 s) : 0, 1220800
Total [baseline] (9.396 s) : 0, 9396121
Agent [candidate] (1.206 s) : 0, 1206471
Total [candidate] (9.437 s) : 0, 9436994
section profiling
Agent [baseline] (1.272 s) : 0, 1272379
Total [baseline] (9.365 s) : 0, 9364866
Agent [candidate] (1.295 s) : 0, 1295359
Total [candidate] (9.433 s) : 0, 9432794
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.076 s -
Agent appsec 1.211 s 135.073 ms (12.5%)
Agent iast 1.221 s 144.513 ms (13.4%)
Agent profiling 1.272 s 196.092 ms (18.2%)
Total tracing 9.117 s -
Total appsec 9.351 s 234.438 ms (2.6%)
Total iast 9.396 s 279.294 ms (3.1%)
Total profiling 9.365 s 248.039 ms (2.7%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.078 s -
Agent appsec 1.205 s 126.799 ms (11.8%)
Agent iast 1.206 s 128.523 ms (11.9%)
Agent profiling 1.295 s 217.412 ms (20.2%)
Total tracing 9.113 s -
Total appsec 9.307 s 194.238 ms (2.1%)
Total iast 9.437 s 324.311 ms (3.6%)
Total profiling 9.433 s 320.111 ms (3.5%) 
gantt
    title petclinic - break down per module: candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (687.343 ms) : 0, 687343
BytebuddyAgent [candidate] (687.108 ms) : 0, 687108
GlobalTracer [baseline] (296.87 ms) : 0, 296870
GlobalTracer [candidate] (298.647 ms) : 0, 298647
AppSec [baseline] (49.249 ms) : 0, 49249
AppSec [candidate] (49.299 ms) : 0, 49299
Remote Config [baseline] (1.073 ms) : 0, 1073
Remote Config [candidate] (1.052 ms) : 0, 1052
Telemetry [baseline] (7.444 ms) : 0, 7444
Telemetry [candidate] (7.522 ms) : 0, 7522
section appsec
BytebuddyAgent [baseline] (701.94 ms) : 0, 701940
BytebuddyAgent [candidate] (697.599 ms) : 0, 697599
GlobalTracer [baseline] (293.548 ms) : 0, 293548
GlobalTracer [candidate] (292.733 ms) : 0, 292733
AppSec [baseline] (154.375 ms) : 0, 154375
AppSec [candidate] (153.332 ms) : 0, 153332
IAST [baseline] (19.477 ms) : 0, 19477
IAST [candidate] (19.304 ms) : 0, 19304
Remote Config [baseline] (620.453 µs) : 0, 620
Remote Config [candidate] (611.581 µs) : 0, 612
Telemetry [baseline] (6.865 ms) : 0, 6865
Telemetry [candidate] (6.78 ms) : 0, 6780
section iast
BytebuddyAgent [baseline] (810.696 ms) : 0, 810696
BytebuddyAgent [candidate] (799.97 ms) : 0, 799970
GlobalTracer [baseline] (292.837 ms) : 0, 292837
GlobalTracer [candidate] (290.209 ms) : 0, 290209
AppSec [baseline] (50.558 ms) : 0, 50558
AppSec [candidate] (48.976 ms) : 0, 48976
IAST [baseline] (24.573 ms) : 0, 24573
IAST [candidate] (23.543 ms) : 0, 23543
Remote Config [baseline] (580.966 µs) : 0, 581
Remote Config [candidate] (565.628 µs) : 0, 566
Telemetry [baseline] (6.621 ms) : 0, 6621
Telemetry [candidate] (8.876 ms) : 0, 8876
section profiling
BytebuddyAgent [baseline] (680.293 ms) : 0, 680293
BytebuddyAgent [candidate] (693.394 ms) : 0, 693394
GlobalTracer [baseline] (382.255 ms) : 0, 382255
GlobalTracer [candidate] (388.418 ms) : 0, 388418
AppSec [baseline] (49.492 ms) : 0, 49492
AppSec [candidate] (50.488 ms) : 0, 50488
Remote Config [baseline] (882.002 µs) : 0, 882
Remote Config [candidate] (870.7 µs) : 0, 871
Telemetry [baseline] (7.46 ms) : 0, 7460
Telemetry [candidate] (7.628 ms) : 0, 7628
ProfilingAgent [baseline] (95.639 ms) : 0, 95639
ProfilingAgent [candidate] (97.192 ms) : 0, 97192
Profiling [baseline] (95.664 ms) : 0, 95664
Profiling [candidate] (97.216 ms) : 0, 97216
Startup time reports for insecure-bank 
gantt
    title insecure-bank - global startup overhead: candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.082 s) : 0, 1082247
Total [baseline] (8.588 s) : 0, 8588353
Agent [candidate] (1.08 s) : 0, 1079847
Total [candidate] (8.567 s) : 0, 8567072
section iast
Agent [baseline] (1.201 s) : 0, 1201480
Total [baseline] (9.035 s) : 0, 9035359
Agent [candidate] (1.206 s) : 0, 1206177
Total [candidate] (9.055 s) : 0, 9055184
section iast_HARDCODED_SECRET_DISABLED
Agent [baseline] (1.213 s) : 0, 1212654
Total [baseline] (9.041 s) : 0, 9040796
Agent [candidate] (1.207 s) : 0, 1206598
Total [candidate] (9.036 s) : 0, 9036409
section iast_TELEMETRY_OFF
Agent [baseline] (1.197 s) : 0, 1197299
Total [baseline] (9.063 s) : 0, 9063344
Agent [candidate] (1.208 s) : 0, 1207940
Total [candidate] (9.124 s) : 0, 9124364
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.082 s -
Agent iast 1.201 s 119.233 ms (11.0%)
Agent iast_HARDCODED_SECRET_DISABLED 1.213 s 130.407 ms (12.0%)
Agent iast_TELEMETRY_OFF 1.197 s 115.052 ms (10.6%)
Total tracing 8.588 s -
Total iast 9.035 s 447.006 ms (5.2%)
Total iast_HARDCODED_SECRET_DISABLED 9.041 s 452.443 ms (5.3%)
Total iast_TELEMETRY_OFF 9.063 s 474.991 ms (5.5%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.08 s -
Agent iast 1.206 s 126.331 ms (11.7%)
Agent iast_HARDCODED_SECRET_DISABLED 1.207 s 126.751 ms (11.7%)
Agent iast_TELEMETRY_OFF 1.208 s 128.093 ms (11.9%)
Total tracing 8.567 s -
Total iast 9.055 s 488.112 ms (5.7%)
Total iast_HARDCODED_SECRET_DISABLED 9.036 s 469.337 ms (5.5%)
Total iast_TELEMETRY_OFF 9.124 s 557.291 ms (6.5%) 
gantt
    title insecure-bank - break down per module: candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (689.798 ms) : 0, 689798
BytebuddyAgent [candidate] (689.001 ms) : 0, 689001
GlobalTracer [baseline] (299.752 ms) : 0, 299752
GlobalTracer [candidate] (298.602 ms) : 0, 298602
AppSec [baseline] (49.636 ms) : 0, 49636
AppSec [candidate] (49.291 ms) : 0, 49291
Remote Config [baseline] (1.092 ms) : 0, 1092
Remote Config [candidate] (1.086 ms) : 0, 1086
Telemetry [baseline] (7.549 ms) : 0, 7549
Telemetry [candidate] (7.485 ms) : 0, 7485
section iast
BytebuddyAgent [baseline] (796.534 ms) : 0, 796534
BytebuddyAgent [candidate] (799.828 ms) : 0, 799828
GlobalTracer [baseline] (288.873 ms) : 0, 288873
GlobalTracer [candidate] (289.955 ms) : 0, 289955
AppSec [baseline] (49.455 ms) : 0, 49455
AppSec [candidate] (48.147 ms) : 0, 48147
IAST [baseline] (24.495 ms) : 0, 24495
IAST [candidate] (25.982 ms) : 0, 25982
Remote Config [baseline] (571.252 µs) : 0, 571
Remote Config [candidate] (566.086 µs) : 0, 566
Telemetry [baseline] (7.312 ms) : 0, 7312
Telemetry [candidate] (7.323 ms) : 0, 7323
section iast_HARDCODED_SECRET_DISABLED
BytebuddyAgent [baseline] (804.784 ms) : 0, 804784
BytebuddyAgent [candidate] (799.091 ms) : 0, 799091
GlobalTracer [baseline] (291.163 ms) : 0, 291163
GlobalTracer [candidate] (290.484 ms) : 0, 290484
AppSec [baseline] (49.775 ms) : 0, 49775
AppSec [candidate] (49.265 ms) : 0, 49265
IAST [baseline] (24.464 ms) : 0, 24464
IAST [candidate] (26.182 ms) : 0, 26182
Remote Config [baseline] (563.607 µs) : 0, 564
Remote Config [candidate] (574.169 µs) : 0, 574
Telemetry [baseline] (7.281 ms) : 0, 7281
Telemetry [candidate] (6.524 ms) : 0, 6524
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (794.013 ms) : 0, 794013
BytebuddyAgent [candidate] (799.255 ms) : 0, 799255
GlobalTracer [baseline] (289.418 ms) : 0, 289418
GlobalTracer [candidate] (291.745 ms) : 0, 291745
AppSec [baseline] (50.18 ms) : 0, 50180
AppSec [candidate] (50.051 ms) : 0, 50051
IAST [baseline] (21.57 ms) : 0, 21570
IAST [candidate] (24.279 ms) : 0, 24279
Remote Config [baseline] (580.23 µs) : 0, 580
Remote Config [candidate] (585.321 µs) : 0, 585
Telemetry [baseline] (7.301 ms) : 0, 7301
Telemetry [candidate] (7.379 ms) : 0, 7379

Load

Request duration reports for petclinic 
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.348 ms) : 1329, 1367
.   : milestone, 1348,
appsec (1.777 ms) : 1754, 1800
.   : milestone, 1777,
iast (1.506 ms) : 1483, 1529
.   : milestone, 1506,
profiling (1.536 ms) : 1513, 1560
.   : milestone, 1536,
tracing (1.518 ms) : 1495, 1542
.   : milestone, 1518,
section candidate
no_agent (1.356 ms) : 1336, 1375
.   : milestone, 1356,
appsec (1.778 ms) : 1755, 1801
.   : milestone, 1778,
iast (1.528 ms) : 1505, 1551
.   : milestone, 1528,
profiling (1.552 ms) : 1529, 1576
.   : milestone, 1552,
tracing (1.505 ms) : 1482, 1529
.   : milestone, 1505,
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.348 ms [1.329 ms, 1.367 ms] -
appsec 1.777 ms [1.754 ms, 1.8 ms] 428.884 µs (31.8%)
iast 1.506 ms [1.483 ms, 1.529 ms] 157.749 µs (11.7%)
profiling 1.536 ms [1.513 ms, 1.56 ms] 188.212 µs (14.0%)
tracing 1.518 ms [1.495 ms, 1.542 ms] 170.013 µs (12.6%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.356 ms [1.336 ms, 1.375 ms] -
appsec 1.778 ms [1.755 ms, 1.801 ms] 421.989 µs (31.1%)
iast 1.528 ms [1.505 ms, 1.551 ms] 172.436 µs (12.7%)
profiling 1.552 ms [1.529 ms, 1.576 ms] 196.458 µs (14.5%)
tracing 1.505 ms [1.482 ms, 1.529 ms] 149.487 µs (11.0%)
Request duration reports for insecure-bank 
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~387b7187e6, baseline=1.32.0-SNAPSHOT~45ff2b9808
    dateFormat X
    axisFormat %s
section baseline
no_agent (365.417 µs) : 345, 385
.   : milestone, 365,
iast (472.944 µs) : 453, 493
.   : milestone, 473,
iast_FULL (545.931 µs) : 525, 567
.   : milestone, 546,
iast_GLOBAL (500.601 µs) : 479, 522
.   : milestone, 501,
iast_HARDCODED_SECRET_DISABLED (472.389 µs) : 452, 493
.   : milestone, 472,
iast_INACTIVE (444.936 µs) : 424, 466
.   : milestone, 445,
iast_TELEMETRY_OFF (475.889 µs) : 455, 496
.   : milestone, 476,
tracing (442.99 µs) : 422, 464
.   : milestone, 443,
section candidate
no_agent (360.219 µs) : 340, 380
.   : milestone, 360,
iast (477.813 µs) : 457, 499
.   : milestone, 478,
iast_FULL (542.442 µs) : 522, 563
.   : milestone, 542,
iast_GLOBAL (497.329 µs) : 476, 519
.   : milestone, 497,
iast_HARDCODED_SECRET_DISABLED (477.337 µs) : 457, 498
.   : milestone, 477,
iast_INACTIVE (444.505 µs) : 424, 465
.   : milestone, 445,
iast_TELEMETRY_OFF (471.881 µs) : 451, 493
.   : milestone, 472,
tracing (446.548 µs) : 426, 467
.   : milestone, 447,
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 365.417 µs [345.36 µs, 385.474 µs] -
iast 472.944 µs [452.573 µs, 493.315 µs] 107.527 µs (29.4%)
iast_FULL 545.931 µs [525.202 µs, 566.661 µs] 180.514 µs (49.4%)
iast_GLOBAL 500.601 µs [479.096 µs, 522.106 µs] 135.184 µs (37.0%)
iast_HARDCODED_SECRET_DISABLED 472.389 µs [451.802 µs, 492.976 µs] 106.972 µs (29.3%)
iast_INACTIVE 444.936 µs [424.013 µs, 465.86 µs] 79.519 µs (21.8%)
iast_TELEMETRY_OFF 475.889 µs [455.473 µs, 496.305 µs] 110.472 µs (30.2%)
tracing 442.99 µs [422.445 µs, 463.536 µs] 77.573 µs (21.2%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 360.219 µs [340.353 µs, 380.085 µs] -
iast 477.813 µs [457.027 µs, 498.598 µs] 117.593 µs (32.6%)
iast_FULL 542.442 µs [522.019 µs, 562.865 µs] 182.223 µs (50.6%)
iast_GLOBAL 497.329 µs [475.733 µs, 518.925 µs] 137.11 µs (38.1%)
iast_HARDCODED_SECRET_DISABLED 477.337 µs [456.816 µs, 497.858 µs] 117.118 µs (32.5%)
iast_INACTIVE 444.505 µs [423.997 µs, 465.012 µs] 84.285 µs (23.4%)
iast_TELEMETRY_OFF 471.881 µs [450.948 µs, 492.813 µs] 111.661 µs (31.0%)
tracing 446.548 µs [425.808 µs, 467.289 µs] 86.329 µs (24.0%)

jbachorik
jbachorik reviewed Mar 21, 2024
View reviewed changes
dd-trace-api/src/main/java/datadog/trace/api/config/ProfilingConfig.java
Comment on lines -191 to +195
"profiling.experimental.queueing.time.enabled";
public static final String PROFILING_QUEUEING_TIME_ENABLED = "profiling.queueing.time.enabled";

public static final boolean PROFILING_QUEUEING_TIME_ENABLED_DEFAULT = false;
public static final boolean PROFILING_QUEUEING_TIME_ENABLED_DEFAULT = true;

public static final String PROFILING_QUEUEING_TIME_THRESHOLD_MILLIS =
"profiling.experimental.queueing.time.threshold.millis";
"profiling.queueing.time.threshold.millis";
Copy link
Contributor

Choose a reason for hiding this comment

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

Just a note - this will have to have a release note just in case there are some customer actually using the experimental config.

@richardstartin richardstartin merged commit 78b3d6c into master Mar 21, 2024
80 checks passed
@richardstartin richardstartin deleted the rgs/ga-queue-time branch March 21, 2024 16:06
@github-actions github-actions bot added this to the 1.32.0 milestone Mar 21, 2024
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

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

Assignees
No one assigned
Labels
comp: profiling Profiling
Projects
None yet
Milestone
1.32.0
Development

Successfully merging this pull request may close these issues.

None yet
2 participants
@richardstartin @jbachorik