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

Reduce logging noise in CI Visibility #6825

Merged
merged 2 commits into from Mar 20, 2024
Merged

Reduce logging noise in CI Visibility #6825

merged 2 commits into from Mar 20, 2024

Conversation

nikita-tkachenko-datadog
Copy link
Contributor

@nikita-tkachenko-datadog nikita-tkachenko-datadog commented Mar 19, 2024 •
edited by jira bot

What Does This Do

Decreases log level of INFO logs to DEBUG.
The only log statement with level INFO left is the one that prints CI Visibility settings when the tracer is initialised.

Also updates logic that propagates system properties from parent process (Maven/Gradle) to children processes: not only dd.* properties are now propagated, but also datadog.* properties.
This is needed to ensure that datadog.slf4j.simpleLogger.defaultLogLevel property is propagated from parent to children.

Motivation

There is a CI Visibility customer complaining about the logs being too noisy.

Jira ticket: APMS-11714

@nikita-tkachenko-datadog nikita-tkachenko-datadog added the comp: ci visibility Continuous Integration Visibility label Mar 19, 2024
@pr-commenter
Copy link

pr-commenter bot commented Mar 19, 2024

Benchmarks

Startup

Parameters

Baseline Candidate
baseline_or_candidate baseline candidate
git_branch master nikita-tkachenko/reduce-ci-vis-log-noise
git_commit_date 1710833793 1710863315
git_commit_sha f97f632 3c6c92b
release_version 1.32.0-SNAPSHOT~f97f63248a 1.32.0-SNAPSHOT~3c6c92bc5b
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
ci_job_date 1710866552 1710866552
ci_job_id 463499355 463499355
ci_pipeline_id 30377240 30377240
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~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.092 s) : 0, 1091549
Total [baseline] (9.222 s) : 0, 9222276
Agent [candidate] (1.081 s) : 0, 1081335
Total [candidate] (9.157 s) : 0, 9157428
section appsec
Agent [baseline] (1.209 s) : 0, 1208560
Total [baseline] (9.339 s) : 0, 9338669
Agent [candidate] (1.204 s) : 0, 1203954
Total [candidate] (9.311 s) : 0, 9310895
section iast
Agent [baseline] (1.22 s) : 0, 1219899
Total [baseline] (9.355 s) : 0, 9354627
Agent [candidate] (1.216 s) : 0, 1216409
Total [candidate] (9.379 s) : 0, 9379376
section profiling
Agent [baseline] (1.273 s) : 0, 1272517
Total [baseline] (9.337 s) : 0, 9336745
Agent [candidate] (1.273 s) : 0, 1273439
Total [candidate] (9.392 s) : 0, 9392099
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.092 s -
Agent appsec 1.209 s 117.01 ms (10.7%)
Agent iast 1.22 s 128.35 ms (11.8%)
Agent profiling 1.273 s 180.968 ms (16.6%)
Total tracing 9.222 s -
Total appsec 9.339 s 116.392 ms (1.3%)
Total iast 9.355 s 132.35 ms (1.4%)
Total profiling 9.337 s 114.469 ms (1.2%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.081 s -
Agent appsec 1.204 s 122.619 ms (11.3%)
Agent iast 1.216 s 135.074 ms (12.5%)
Agent profiling 1.273 s 192.104 ms (17.8%)
Total tracing 9.157 s -
Total appsec 9.311 s 153.467 ms (1.7%)
Total iast 9.379 s 221.948 ms (2.4%)
Total profiling 9.392 s 234.672 ms (2.6%) 
gantt
    title petclinic - break down per module: candidate=1.32.0-SNAPSHOT~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (704.033 ms) : 0, 704033
BytebuddyAgent [candidate] (696.979 ms) : 0, 696979
GlobalTracer [baseline] (294.441 ms) : 0, 294441
GlobalTracer [candidate] (292.35 ms) : 0, 292350
AppSec [baseline] (49.631 ms) : 0, 49631
AppSec [candidate] (49.233 ms) : 0, 49233
Remote Config [baseline] (1.105 ms) : 0, 1105
Remote Config [candidate] (1.076 ms) : 0, 1076
Telemetry [baseline] (7.518 ms) : 0, 7518
Telemetry [candidate] (7.471 ms) : 0, 7471
section appsec
BytebuddyAgent [baseline] (700.775 ms) : 0, 700775
BytebuddyAgent [candidate] (697.968 ms) : 0, 697968
GlobalTracer [baseline] (293.424 ms) : 0, 293424
GlobalTracer [candidate] (292.441 ms) : 0, 292441
AppSec [baseline] (154.361 ms) : 0, 154361
AppSec [candidate] (153.91 ms) : 0, 153910
IAST [baseline] (17.998 ms) : 0, 17998
IAST [candidate] (17.948 ms) : 0, 17948
Remote Config [baseline] (618.123 µs) : 0, 618
Remote Config [candidate] (612.44 µs) : 0, 612
Telemetry [baseline] (6.895 ms) : 0, 6895
Telemetry [candidate] (6.862 ms) : 0, 6862
section iast
BytebuddyAgent [baseline] (812.087 ms) : 0, 812087
BytebuddyAgent [candidate] (808.859 ms) : 0, 808859
GlobalTracer [baseline] (291.685 ms) : 0, 291685
GlobalTracer [candidate] (291.271 ms) : 0, 291271
AppSec [baseline] (50.693 ms) : 0, 50693
AppSec [candidate] (52.895 ms) : 0, 52895
IAST [baseline] (23.475 ms) : 0, 23475
IAST [candidate] (21.73 ms) : 0, 21730
Remote Config [baseline] (575.591 µs) : 0, 576
Remote Config [candidate] (575.431 µs) : 0, 575
Telemetry [baseline] (6.629 ms) : 0, 6629
Telemetry [candidate] (6.672 ms) : 0, 6672
section profiling
BytebuddyAgent [baseline] (687.713 ms) : 0, 687713
BytebuddyAgent [candidate] (689.045 ms) : 0, 689045
GlobalTracer [baseline] (375.71 ms) : 0, 375710
GlobalTracer [candidate] (375.64 ms) : 0, 375640
AppSec [baseline] (49.968 ms) : 0, 49968
AppSec [candidate] (50.194 ms) : 0, 50194
Remote Config [baseline] (854.249 µs) : 0, 854
Remote Config [candidate] (820.97 µs) : 0, 821
Telemetry [baseline] (7.261 ms) : 0, 7261
Telemetry [candidate] (7.29 ms) : 0, 7290
ProfilingAgent [baseline] (94.996 ms) : 0, 94996
ProfilingAgent [candidate] (94.496 ms) : 0, 94496
Profiling [baseline] (95.019 ms) : 0, 95019
Profiling [candidate] (94.519 ms) : 0, 94519
Startup time reports for insecure-bank 
gantt
    title insecure-bank - global startup overhead: candidate=1.32.0-SNAPSHOT~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.079 s) : 0, 1079492
Total [baseline] (8.601 s) : 0, 8601044
Agent [candidate] (1.088 s) : 0, 1087705
Total [candidate] (8.583 s) : 0, 8582866
section iast
Agent [baseline] (1.207 s) : 0, 1206681
Total [baseline] (9.085 s) : 0, 9085079
Agent [candidate] (1.206 s) : 0, 1206373
Total [candidate] (9.098 s) : 0, 9097751
section iast_HARDCODED_SECRET_DISABLED
Agent [baseline] (1.207 s) : 0, 1207150
Total [baseline] (9.077 s) : 0, 9076788
Agent [candidate] (1.206 s) : 0, 1206041
Total [candidate] (9.029 s) : 0, 9029032
section iast_TELEMETRY_OFF
Agent [baseline] (1.213 s) : 0, 1213430
Total [baseline] (9.076 s) : 0, 9076058
Agent [candidate] (1.203 s) : 0, 1203008
Total [candidate] (9.106 s) : 0, 9106277
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.079 s -
Agent iast 1.207 s 127.189 ms (11.8%)
Agent iast_HARDCODED_SECRET_DISABLED 1.207 s 127.658 ms (11.8%)
Agent iast_TELEMETRY_OFF 1.213 s 133.938 ms (12.4%)
Total tracing 8.601 s -
Total iast 9.085 s 484.035 ms (5.6%)
Total iast_HARDCODED_SECRET_DISABLED 9.077 s 475.743 ms (5.5%)
Total iast_TELEMETRY_OFF 9.076 s 475.014 ms (5.5%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.088 s -
Agent iast 1.206 s 118.668 ms (10.9%)
Agent iast_HARDCODED_SECRET_DISABLED 1.206 s 118.337 ms (10.9%)
Agent iast_TELEMETRY_OFF 1.203 s 115.303 ms (10.6%)
Total tracing 8.583 s -
Total iast 9.098 s 514.885 ms (6.0%)
Total iast_HARDCODED_SECRET_DISABLED 9.029 s 446.166 ms (5.2%)
Total iast_TELEMETRY_OFF 9.106 s 523.411 ms (6.1%) 
gantt
    title insecure-bank - break down per module: candidate=1.32.0-SNAPSHOT~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (696.764 ms) : 0, 696764
BytebuddyAgent [candidate] (701.542 ms) : 0, 701542
GlobalTracer [baseline] (291.285 ms) : 0, 291285
GlobalTracer [candidate] (293.982 ms) : 0, 293982
AppSec [baseline] (48.807 ms) : 0, 48807
AppSec [candidate] (49.26 ms) : 0, 49260
Remote Config [baseline] (1.088 ms) : 0, 1088
Remote Config [candidate] (1.065 ms) : 0, 1065
Telemetry [baseline] (7.339 ms) : 0, 7339
Telemetry [candidate] (7.401 ms) : 0, 7401
section iast
BytebuddyAgent [baseline] (800.108 ms) : 0, 800108
BytebuddyAgent [candidate] (800.806 ms) : 0, 800806
GlobalTracer [baseline] (290.088 ms) : 0, 290088
GlobalTracer [candidate] (289.557 ms) : 0, 289557
AppSec [baseline] (50.92 ms) : 0, 50920
AppSec [candidate] (50.476 ms) : 0, 50476
Remote Config [baseline] (576.545 µs) : 0, 577
Remote Config [candidate] (563.438 µs) : 0, 563
Telemetry [baseline] (7.465 ms) : 0, 7465
Telemetry [candidate] (6.63 ms) : 0, 6630
IAST [baseline] (23.21 ms) : 0, 23210
IAST [candidate] (23.896 ms) : 0, 23896
section iast_HARDCODED_SECRET_DISABLED
BytebuddyAgent [baseline] (802.176 ms) : 0, 802176
BytebuddyAgent [candidate] (800.824 ms) : 0, 800824
GlobalTracer [baseline] (289.516 ms) : 0, 289516
GlobalTracer [candidate] (289.654 ms) : 0, 289654
AppSec [baseline] (50.538 ms) : 0, 50538
AppSec [candidate] (48.937 ms) : 0, 48937
Remote Config [baseline] (577.04 µs) : 0, 577
Remote Config [candidate] (562.005 µs) : 0, 562
Telemetry [baseline] (6.643 ms) : 0, 6643
Telemetry [candidate] (7.302 ms) : 0, 7302
IAST [baseline] (23.285 ms) : 0, 23285
IAST [candidate] (24.475 ms) : 0, 24475
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (804.178 ms) : 0, 804178
BytebuddyAgent [candidate] (795.651 ms) : 0, 795651
GlobalTracer [baseline] (293.088 ms) : 0, 293088
GlobalTracer [candidate] (290.977 ms) : 0, 290977
AppSec [baseline] (49.486 ms) : 0, 49486
AppSec [candidate] (50.604 ms) : 0, 50604
Remote Config [baseline] (577.368 µs) : 0, 577
Remote Config [candidate] (593.185 µs) : 0, 593
Telemetry [baseline] (6.574 ms) : 0, 6574
Telemetry [candidate] (6.642 ms) : 0, 6642
IAST [baseline] (24.84 ms) : 0, 24840
IAST [candidate] (24.149 ms) : 0, 24149

Load

Request duration reports for petclinic 
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.361 ms) : 1342, 1380
.   : milestone, 1361,
appsec (1.798 ms) : 1775, 1821
.   : milestone, 1798,
iast (1.535 ms) : 1512, 1559
.   : milestone, 1535,
profiling (1.564 ms) : 1540, 1589
.   : milestone, 1564,
tracing (1.515 ms) : 1491, 1538
.   : milestone, 1515,
section candidate
no_agent (1.355 ms) : 1336, 1374
.   : milestone, 1355,
appsec (1.792 ms) : 1768, 1815
.   : milestone, 1792,
iast (1.528 ms) : 1506, 1551
.   : milestone, 1528,
profiling (1.596 ms) : 1572, 1621
.   : milestone, 1596,
tracing (1.491 ms) : 1468, 1515
.   : milestone, 1491,
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.361 ms [1.342 ms, 1.38 ms] -
appsec 1.798 ms [1.775 ms, 1.821 ms] 437.246 µs (32.1%)
iast 1.535 ms [1.512 ms, 1.559 ms] 174.657 µs (12.8%)
profiling 1.564 ms [1.54 ms, 1.589 ms] 203.259 µs (14.9%)
tracing 1.515 ms [1.491 ms, 1.538 ms] 153.79 µs (11.3%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.355 ms [1.336 ms, 1.374 ms] -
appsec 1.792 ms [1.768 ms, 1.815 ms] 436.639 µs (32.2%)
iast 1.528 ms [1.506 ms, 1.551 ms] 173.361 µs (12.8%)
profiling 1.596 ms [1.572 ms, 1.621 ms] 241.079 µs (17.8%)
tracing 1.491 ms [1.468 ms, 1.515 ms] 136.232 µs (10.1%)
Request duration reports for insecure-bank 
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.32.0-SNAPSHOT~3c6c92bc5b, baseline=1.32.0-SNAPSHOT~f97f63248a
    dateFormat X
    axisFormat %s
section baseline
no_agent (379.172 µs) : 357, 401
.   : milestone, 379,
iast (476.963 µs) : 457, 497
.   : milestone, 477,
iast_FULL (541.548 µs) : 521, 562
.   : milestone, 542,
iast_GLOBAL (504.708 µs) : 484, 526
.   : milestone, 505,
iast_HARDCODED_SECRET_DISABLED (483.548 µs) : 463, 504
.   : milestone, 484,
iast_INACTIVE (451.085 µs) : 431, 471
.   : milestone, 451,
iast_TELEMETRY_OFF (478.905 µs) : 458, 500
.   : milestone, 479,
tracing (446.187 µs) : 426, 467
.   : milestone, 446,
section candidate
no_agent (371.744 µs) : 351, 392
.   : milestone, 372,
iast (474.589 µs) : 454, 495
.   : milestone, 475,
iast_FULL (548.144 µs) : 527, 569
.   : milestone, 548,
iast_GLOBAL (503.802 µs) : 482, 526
.   : milestone, 504,
iast_HARDCODED_SECRET_DISABLED (477.015 µs) : 457, 497
.   : milestone, 477,
iast_INACTIVE (456.243 µs) : 436, 477
.   : milestone, 456,
iast_TELEMETRY_OFF (479.899 µs) : 459, 501
.   : milestone, 480,
tracing (445.843 µs) : 426, 466
.   : milestone, 446,
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 379.172 µs [357.05 µs, 401.295 µs] -
iast 476.963 µs [456.601 µs, 497.325 µs] 97.791 µs (25.8%)
iast_FULL 541.548 µs [521.237 µs, 561.859 µs] 162.376 µs (42.8%)
iast_GLOBAL 504.708 µs [483.673 µs, 525.743 µs] 125.536 µs (33.1%)
iast_HARDCODED_SECRET_DISABLED 483.548 µs [462.689 µs, 504.407 µs] 104.376 µs (27.5%)
iast_INACTIVE 451.085 µs [430.748 µs, 471.421 µs] 71.913 µs (19.0%)
iast_TELEMETRY_OFF 478.905 µs [458.028 µs, 499.781 µs] 99.732 µs (26.3%)
tracing 446.187 µs [425.533 µs, 466.841 µs] 67.014 µs (17.7%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 371.744 µs [351.021 µs, 392.467 µs] -
iast 474.589 µs [454.43 µs, 494.748 µs] 102.845 µs (27.7%)
iast_FULL 548.144 µs [527.496 µs, 568.792 µs] 176.4 µs (47.5%)
iast_GLOBAL 503.802 µs [482.02 µs, 525.583 µs] 132.058 µs (35.5%)
iast_HARDCODED_SECRET_DISABLED 477.015 µs [456.638 µs, 497.392 µs] 105.271 µs (28.3%)
iast_INACTIVE 456.243 µs [435.827 µs, 476.659 µs] 84.499 µs (22.7%)
iast_TELEMETRY_OFF 479.899 µs [459.173 µs, 500.625 µs] 108.155 µs (29.1%)
tracing 445.843 µs [425.653 µs, 466.033 µs] 74.099 µs (19.9%)

@nikita-tkachenko-datadog nikita-tkachenko-datadog marked this pull request as ready for review March 20, 2024 11:59
@nikita-tkachenko-datadog nikita-tkachenko-datadog requested a review from a team as a code owner March 20, 2024 11:59
@nikita-tkachenko-datadog nikita-tkachenko-datadog merged commit e20dfff into master Mar 20, 2024
73 checks passed
@nikita-tkachenko-datadog nikita-tkachenko-datadog deleted the nikita-tkachenko/reduce-ci-vis-log-noise branch March 20, 2024 12:43
@github-actions github-actions bot added this to the 1.32.0 milestone Mar 20, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@juan-fernandez juan-fernandez juan-fernandez approved these changes

Assignees
No one assigned
Labels
comp: ci visibility Continuous Integration Visibility
Projects
None yet
Milestone
1.32.0
Development

Successfully merging this pull request may close these issues.

None yet
2 participants
@nikita-tkachenko-datadog @juan-fernandez