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

Fix tracer logging when instrumenting Gradle Daemon #6080

Merged
merged 2 commits into from
Oct 25, 2023
Merged

Fix tracer logging when instrumenting Gradle Daemon #6080

merged 2 commits into from
Oct 25, 2023

Conversation

nikita-tkachenko-datadog
Copy link
Contributor

@nikita-tkachenko-datadog nikita-tkachenko-datadog commented Oct 23, 2023 •
edited
Loading

What Does This Do

Fixes tracer logging to work when instrumenting Gradle Daemon.

Motivation

Tracer logs contain data that is important for debugging.

When Gradle Daemon initialises, it closes original System.out and System.err streams, replacing them with daemon log streams.
Tracer logging is initialised before the daemon, so it refers to the original streams that are closed.
In order for the logging to work, it needs to refer to the daemon log streams.
This is achieved by reinitialising logging settings after Gradle Daemon has finished its initialisation.

Jira ticket: CIVIS-7730

@nikita-tkachenko-datadog nikita-tkachenko-datadog added type: bug comp: ci visibility Continuous Integration Visibility labels Oct 23, 2023
@pr-commenter
Copy link

pr-commenter bot commented Oct 23, 2023 •
edited
Loading

Benchmarks

Startup

Parameters

Baseline Candidate
commit 1.22.0-SNAPSHOT~9a80d519df 1.22.0-SNAPSHOT~3407cf2fba
config baseline candidate
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
module Agent Agent
parent None None
variant iast iast

Summary

Found 1 performance improvements and 0 performance regressions! Performance is the same for 53 cases.

scenario Δ mean execution_time candidate mean execution_time baseline mean execution_time
scenario:insecure-bank:iast:Telemetry better
[-5.182ms; -0.421ms] or [-62.506%; -5.073%]		 5.490ms 8.291ms
Startup time reports for petclinic 
gantt
    title petclinic - global startup overhead: candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.012 s) : 0, 1012152
Total [baseline] (9.212 s) : 0, 9211891
Agent [candidate] (1.017 s) : 0, 1017287
Total [candidate] (9.286 s) : 0, 9286307
section appsec
Agent [baseline] (1.103 s) : 0, 1102612
Total [baseline] (9.287 s) : 0, 9286669
Agent [candidate] (1.103 s) : 0, 1103438
Total [candidate] (9.332 s) : 0, 9331838
section iast
Agent [baseline] (1.155 s) : 0, 1155483
Total [baseline] (9.504 s) : 0, 9503806
Agent [candidate] (1.145 s) : 0, 1144925
Total [candidate] (9.431 s) : 0, 9430687
section profiling
Agent [baseline] (1.2 s) : 0, 1199778
Total [baseline] (9.476 s) : 0, 9475593
Agent [candidate] (1.197 s) : 0, 1196567
Total [candidate] (9.601 s) : 0, 9600729
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.012 s -
Agent appsec 1.103 s 90.46 ms (8.9%)
Agent iast 1.155 s 143.332 ms (14.2%)
Agent profiling 1.2 s 187.627 ms (18.5%)
Total tracing 9.212 s -
Total appsec 9.287 s 74.778 ms (0.8%)
Total iast 9.504 s 291.915 ms (3.2%)
Total profiling 9.476 s 263.703 ms (2.9%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.017 s -
Agent appsec 1.103 s 86.15 ms (8.5%)
Agent iast 1.145 s 127.638 ms (12.5%)
Agent profiling 1.197 s 179.28 ms (17.6%)
Total tracing 9.286 s -
Total appsec 9.332 s 45.531 ms (0.5%)
Total iast 9.431 s 144.38 ms (1.6%)
Total profiling 9.601 s 314.422 ms (3.4%) 
gantt
    title petclinic - break down per module: candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (630.889 ms) : 0, 630889
BytebuddyAgent [candidate] (633.733 ms) : 0, 633733
GlobalTracer [baseline] (291.653 ms) : 0, 291653
GlobalTracer [candidate] (293.375 ms) : 0, 293375
AppSec [baseline] (48.711 ms) : 0, 48711
AppSec [candidate] (49.129 ms) : 0, 49129
Remote Config [baseline] (654.958 µs) : 0, 655
Remote Config [candidate] (661.196 µs) : 0, 661
Telemetry [baseline] (5.983 ms) : 0, 5983
Telemetry [candidate] (6.03 ms) : 0, 6030
section appsec
BytebuddyAgent [baseline] (632.649 ms) : 0, 632649
BytebuddyAgent [candidate] (632.851 ms) : 0, 632851
GlobalTracer [baseline] (291.848 ms) : 0, 291848
GlobalTracer [candidate] (292.348 ms) : 0, 292348
AppSec [baseline] (137.508 ms) : 0, 137508
AppSec [candidate] (137.706 ms) : 0, 137706
Remote Config [baseline] (638.573 µs) : 0, 639
Remote Config [candidate] (639.542 µs) : 0, 640
Telemetry [baseline] (5.685 ms) : 0, 5685
Telemetry [candidate] (5.703 ms) : 0, 5703
section iast
BytebuddyAgent [baseline] (771.709 ms) : 0, 771709
BytebuddyAgent [candidate] (763.478 ms) : 0, 763478
GlobalTracer [baseline] (276.09 ms) : 0, 276090
GlobalTracer [candidate] (273.41 ms) : 0, 273410
AppSec [baseline] (47.055 ms) : 0, 47055
AppSec [candidate] (46.558 ms) : 0, 46558
Remote Config [baseline] (592.135 µs) : 0, 592
Remote Config [candidate] (587.365 µs) : 0, 587
Telemetry [baseline] (7.694 ms) : 0, 7694
Telemetry [candidate] (7.597 ms) : 0, 7597
IAST [baseline] (17.612 ms) : 0, 17612
IAST [candidate] (18.926 ms) : 0, 18926
section profiling
ProfilingAgent [baseline] (81.065 ms) : 0, 81065
ProfilingAgent [candidate] (81.09 ms) : 0, 81090
BytebuddyAgent [baseline] (651.4 ms) : 0, 651400
BytebuddyAgent [candidate] (648.291 ms) : 0, 648291
GlobalTracer [baseline] (357.213 ms) : 0, 357213
GlobalTracer [candidate] (357.278 ms) : 0, 357278
AppSec [baseline] (49.324 ms) : 0, 49324
AppSec [candidate] (49.485 ms) : 0, 49485
Remote Config [baseline] (662.323 µs) : 0, 662
Remote Config [candidate] (672.789 µs) : 0, 673
Telemetry [baseline] (6.096 ms) : 0, 6096
Telemetry [candidate] (6.129 ms) : 0, 6129
Profiling [baseline] (81.091 ms) : 0, 81091
Profiling [candidate] (81.114 ms) : 0, 81114
Loading
Startup time reports for insecure-bank 
gantt
    title insecure-bank - global startup overhead: candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.012 s) : 0, 1012289
Total [baseline] (8.692 s) : 0, 8691975
Agent [candidate] (1.023 s) : 0, 1022517
Total [candidate] (8.714 s) : 0, 8714106
section iast
Agent [baseline] (1.156 s) : 0, 1155839
Total [baseline] (9.313 s) : 0, 9313305
Agent [candidate] (1.14 s) : 0, 1139826
Total [candidate] (9.226 s) : 0, 9226262
section iast_TELEMETRY_OFF
Agent [baseline] (1.143 s) : 0, 1142726
Total [baseline] (9.233 s) : 0, 9233340
Agent [candidate] (1.132 s) : 0, 1131816
Total [candidate] (9.197 s) : 0, 9197299
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 1.012 s -
Agent iast 1.156 s 143.55 ms (14.2%)
Agent iast_TELEMETRY_OFF 1.143 s 130.436 ms (12.9%)
Total tracing 8.692 s -
Total iast 9.313 s 621.33 ms (7.1%)
Total iast_TELEMETRY_OFF 9.233 s 541.365 ms (6.2%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 1.023 s -
Agent iast 1.14 s 117.309 ms (11.5%)
Agent iast_TELEMETRY_OFF 1.132 s 109.299 ms (10.7%)
Total tracing 8.714 s -
Total iast 9.226 s 512.156 ms (5.9%)
Total iast_TELEMETRY_OFF 9.197 s 483.193 ms (5.5%) 
gantt
    title insecure-bank - break down per module: candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (630.914 ms) : 0, 630914
BytebuddyAgent [candidate] (636.979 ms) : 0, 636979
GlobalTracer [baseline] (291.566 ms) : 0, 291566
GlobalTracer [candidate] (294.653 ms) : 0, 294653
AppSec [baseline] (48.943 ms) : 0, 48943
AppSec [candidate] (49.55 ms) : 0, 49550
Remote Config [baseline] (660.656 µs) : 0, 661
Remote Config [candidate] (666.805 µs) : 0, 667
Telemetry [baseline] (5.944 ms) : 0, 5944
Telemetry [candidate] (6.065 ms) : 0, 6065
section iast
BytebuddyAgent [baseline] (772.275 ms) : 0, 772275
BytebuddyAgent [candidate] (760.785 ms) : 0, 760785
GlobalTracer [baseline] (275.657 ms) : 0, 275657
GlobalTracer [candidate] (272.595 ms) : 0, 272595
AppSec [baseline] (46.645 ms) : 0, 46645
AppSec [candidate] (45.944 ms) : 0, 45944
IAST [baseline] (17.641 ms) : 0, 17641
IAST [candidate] (20.184 ms) : 0, 20184
Remote Config [baseline] (572.103 µs) : 0, 572
Remote Config [candidate] (582.984 µs) : 0, 583
Telemetry [baseline] (8.291 ms) : 0, 8291
Telemetry [candidate] (5.49 ms) : 0, 5490
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (761.322 ms) : 0, 761322
BytebuddyAgent [candidate] (753.939 ms) : 0, 753939
GlobalTracer [baseline] (274.953 ms) : 0, 274953
GlobalTracer [candidate] (272.742 ms) : 0, 272742
AppSec [baseline] (46.486 ms) : 0, 46486
AppSec [candidate] (46.356 ms) : 0, 46356
IAST [baseline] (17.116 ms) : 0, 17116
IAST [candidate] (17.069 ms) : 0, 17069
Remote Config [baseline] (583.449 µs) : 0, 583
Remote Config [candidate] (582.988 µs) : 0, 583
Telemetry [baseline] (7.677 ms) : 0, 7677
Telemetry [candidate] (6.926 ms) : 0, 6926
Loading

Load

Parameters

Baseline Candidate
commit 1.22.0-SNAPSHOT~9a80d519df 1.22.0-SNAPSHOT~3407cf2fba
config baseline candidate
end_time 2023-10-23T13:24:18 2023-10-23T13:40:35
start_time 2023-10-23T13:24:05 2023-10-23T13:40:22
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
variant iast iast

Summary

Found 0 performance improvements and 0 performance regressions! Performance is the same for 22 cases.

Request duration reports for petclinic 
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.343 ms) : 1324, 1362
.   : milestone, 1343,
appsec (1.694 ms) : 1669, 1718
.   : milestone, 1694,
iast (1.453 ms) : 1429, 1477
.   : milestone, 1453,
profiling (1.46 ms) : 1436, 1485
.   : milestone, 1460,
tracing (1.45 ms) : 1426, 1475
.   : milestone, 1450,
section candidate
no_agent (1.33 ms) : 1311, 1349
.   : milestone, 1330,
appsec (1.699 ms) : 1675, 1724
.   : milestone, 1699,
iast (1.447 ms) : 1423, 1472
.   : milestone, 1447,
profiling (1.456 ms) : 1432, 1481
.   : milestone, 1456,
tracing (1.441 ms) : 1416, 1466
.   : milestone, 1441,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.343 ms [1.324 ms, 1.362 ms] -
appsec 1.694 ms [1.669 ms, 1.718 ms] 351.088 µs (26.1%)
iast 1.453 ms [1.429 ms, 1.477 ms] 110.147 µs (8.2%)
profiling 1.46 ms [1.436 ms, 1.485 ms] 117.773 µs (8.8%)
tracing 1.45 ms [1.426 ms, 1.475 ms] 107.6 µs (8.0%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.33 ms [1.311 ms, 1.349 ms] -
appsec 1.699 ms [1.675 ms, 1.724 ms] 369.374 µs (27.8%)
iast 1.447 ms [1.423 ms, 1.472 ms] 117.36 µs (8.8%)
profiling 1.456 ms [1.432 ms, 1.481 ms] 126.329 µs (9.5%)
tracing 1.441 ms [1.416 ms, 1.466 ms] 111.079 µs (8.4%)
Request duration reports for insecure-bank 
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.22.0-SNAPSHOT~3407cf2fba, baseline=1.22.0-SNAPSHOT~9a80d519df
    dateFormat X
    axisFormat %s
section baseline
no_agent (370.876 µs) : 350, 392
.   : milestone, 371,
iast (465.558 µs) : 445, 486
.   : milestone, 466,
iast_FULL (526.192 µs) : 506, 547
.   : milestone, 526,
iast_INACTIVE (432.019 µs) : 411, 453
.   : milestone, 432,
iast_TELEMETRY_OFF (463.849 µs) : 443, 485
.   : milestone, 464,
tracing (433.56 µs) : 412, 455
.   : milestone, 434,
section candidate
no_agent (364.431 µs) : 344, 385
.   : milestone, 364,
iast (465.361 µs) : 444, 487
.   : milestone, 465,
iast_FULL (524.278 µs) : 504, 545
.   : milestone, 524,
iast_INACTIVE (431.121 µs) : 411, 451
.   : milestone, 431,
iast_TELEMETRY_OFF (456.682 µs) : 436, 477
.   : milestone, 457,
tracing (437.081 µs) : 416, 458
.   : milestone, 437,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 370.876 µs [349.788 µs, 391.964 µs] -
iast 465.558 µs [444.779 µs, 486.336 µs] 94.681 µs (25.5%)
iast_FULL 526.192 µs [505.697 µs, 546.688 µs] 155.316 µs (41.9%)
iast_INACTIVE 432.019 µs [411.29 µs, 452.748 µs] 61.143 µs (16.5%)
iast_TELEMETRY_OFF 463.849 µs [442.513 µs, 485.186 µs] 92.973 µs (25.1%)
tracing 433.56 µs [412.288 µs, 454.833 µs] 62.684 µs (16.9%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 364.431 µs [344.196 µs, 384.665 µs] -
iast 465.361 µs [443.952 µs, 486.77 µs] 100.93 µs (27.7%)
iast_FULL 524.278 µs [503.723 µs, 544.834 µs] 159.848 µs (43.9%)
iast_INACTIVE 431.121 µs [410.922 µs, 451.32 µs] 66.69 µs (18.3%)
iast_TELEMETRY_OFF 456.682 µs [436.035 µs, 477.33 µs] 92.251 µs (25.3%)
tracing 437.081 µs [416.023 µs, 458.139 µs] 72.65 µs (19.9%)

@nikita-tkachenko-datadog nikita-tkachenko-datadog marked this pull request as ready for review October 23, 2023 12:07
@mcculls mcculls requested a review from bantonsson October 23, 2023 12:33
mcculls
mcculls reviewed Oct 23, 2023
View reviewed changes
internal-api/src/main/java/datadog/trace/api/Resettable.java Outdated

public interface Resettable {
void reset();
}
Copy link
Contributor

Choose a reason for hiding this comment

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

I've added @bantonsson as he knows more about our embedded logger, but I wonder if it makes sense to add such a generic API for such a specific use.

You could instead add a method such as initialize or reset to LogLevelSwitcher and then use the existing GlobalLogLevelSwitcher to drive the reset of DDLoggerFactory. Alternatively you could create a new log-specific interface if you prefer it to be separate from LogLevelSwitcher, but follow a similar pattern.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Good point, I completely overlooked the LogLevelSwitcher interface. Added a new method there instead of Resettable.

@nikita-tkachenko-datadog nikita-tkachenko-datadog merged commit 9824b2e into master Oct 25, 2023
11 checks passed
@nikita-tkachenko-datadog nikita-tkachenko-datadog deleted the nikita-tkachenko/gradle-daemon-logging-fix branch October 25, 2023 08:50
@github-actions github-actions bot added this to the 1.22.0 milestone Oct 25, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@mcculls mcculls mcculls left review comments

@romainkomorn-exdatadog romainkomorn-exdatadog romainkomorn-exdatadog approved these changes

@bantonsson bantonsson bantonsson approved these changes

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

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

Successfully merging this pull request may close these issues.
4 participants
@nikita-tkachenko-datadog @mcculls @bantonsson @romainkomorn-exdatadog