Always set log level on telemetry logs #8916

smola · 2025-06-03T16:12:19Z

What Does This Do

Default telemetry log level to DEBUG.

Motivation

Our telemetry system has only 3 log levels: ERROR, WARN, and DEBUG, and setting a level is mandatory. That means we're currently skipping the field for INFO level.

Additional Notes

Thanks to @sezen-datadog for the heads up.

Contributor Checklist

Format the title according the contribution guidelines
Assign the type: and (comp: or inst:) labels in addition to any usefull labels
Don't use close, fix or any linking keywords when referencing an issue.
Use solves instead, and assign the PR milestone to the issue
Update the CODEOWNERS file on source file addition, move, or deletion
Update the public documentation in case of new configuration flag or behavior

Jira ticket: [PROJ-IDENT]

pr-commenter · 2025-06-03T16:54:30Z

Benchmarks

Startup

Parameters

	Baseline	Candidate
baseline_or_candidate	baseline	candidate
git_branch	master	smola/telemetry-log-level
git_commit_date	1746789389	1748967020
git_commit_sha	`ad6d5fe`	`65c9664`
release_version	1.50.0-SNAPSHOT~ad6d5fef42	1.50.0-SNAPSHOT~65c9664bf5

See matching parameters

	Baseline	Candidate
application	insecure-bank	insecure-bank
ci_job_date	1748969622	1748969622
ci_job_id	965860871	965860871
ci_pipeline_id	66832249	66832249
cpu_model	Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz	Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
kernel_version	Linux runner-rdwhfy8--project-304-concurrent-2-cwwh9dtz 6.8.0-1029-aws #31~22.04.1-Ubuntu SMP Thu Apr 24 21:16:18 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux	Linux runner-rdwhfy8--project-304-concurrent-2-cwwh9dtz 6.8.0-1029-aws #31~22.04.1-Ubuntu SMP Thu Apr 24 21:16:18 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux
module	Agent	Agent
parent	None	None
variant	iast	iast

Summary

Found 4 performance improvements and 1 performance regressions! Performance is the same for 54 metrics, 12 unstable metrics.

scenario	Δ mean execution_time	candidate mean execution_time	baseline mean execution_time
scenario:startup:insecure-bank:iast_TELEMETRY_OFF:AppSec	better [-8.607ms; -3.711ms] or [-15.500%; -6.682%]	49.368ms	55.527ms
scenario:startup:petclinic:profiling:ProfilingAgent	better [-7.751ms; -4.667ms] or [-7.143%; -4.301%]	102.297ms	108.505ms
scenario:startup:petclinic:profiling:GlobalTracer	better [-21.934ms; -14.086ms] or [-5.784%; -3.714%]	361.219ms	379.229ms
scenario:startup:petclinic:profiling:AppSec	worse [+5.550ms; +8.879ms] or [+10.228%; +16.365%]	61.474ms	54.260ms
scenario:startup:petclinic:profiling:Profiling	better [-7.752ms; -4.669ms] or [-7.143%; -4.302%]	102.320ms	108.531ms

Startup time reports for insecure-bank

gantt
    title insecure-bank - global startup overhead: candidate=1.50.0-SNAPSHOT~65c9664bf5, baseline=1.50.0-SNAPSHOT~ad6d5fef42

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.02 s) : 0, 1020090
Total [baseline] (8.507 s) : 0, 8507129
Agent [candidate] (1.023 s) : 0, 1022591
Total [candidate] (8.513 s) : 0, 8513013
section iast
Agent [baseline] (1.147 s) : 0, 1146662
Total [baseline] (9.151 s) : 0, 9151127
Agent [candidate] (1.156 s) : 0, 1156191
Total [candidate] (9.204 s) : 0, 9204307
section iast_HARDCODED_SECRET_DISABLED
Agent [baseline] (1.148 s) : 0, 1147726
Total [baseline] (9.135 s) : 0, 9134947
Agent [candidate] (1.158 s) : 0, 1158220
Total [candidate] (9.159 s) : 0, 9158589
section iast_TELEMETRY_OFF
Agent [baseline] (1.15 s) : 0, 1149536
Total [baseline] (9.239 s) : 0, 9238535
Agent [candidate] (1.145 s) : 0, 1145486
Total [candidate] (9.267 s) : 0, 9266852

baseline results

Module	Variant	Duration	Δ tracing
Agent	tracing	1.02 s	-
Agent	iast	1.147 s	126.571 ms (12.4%)
Agent	iast_HARDCODED_SECRET_DISABLED	1.148 s	127.636 ms (12.5%)
Agent	iast_TELEMETRY_OFF	1.15 s	129.445 ms (12.7%)
Total	tracing	8.507 s	-
Total	iast	9.151 s	643.998 ms (7.6%)
Total	iast_HARDCODED_SECRET_DISABLED	9.135 s	627.818 ms (7.4%)
Total	iast_TELEMETRY_OFF	9.239 s	731.406 ms (8.6%)

candidate results

Module	Variant	Duration	Δ tracing
Agent	tracing	1.023 s	-
Agent	iast	1.156 s	133.6 ms (13.1%)
Agent	iast_HARDCODED_SECRET_DISABLED	1.158 s	135.629 ms (13.3%)
Agent	iast_TELEMETRY_OFF	1.145 s	122.895 ms (12.0%)
Total	tracing	8.513 s	-
Total	iast	9.204 s	691.294 ms (8.1%)
Total	iast_HARDCODED_SECRET_DISABLED	9.159 s	645.576 ms (7.6%)
Total	iast_TELEMETRY_OFF	9.267 s	753.839 ms (8.9%)

gantt
    title insecure-bank - break down per module: candidate=1.50.0-SNAPSHOT~65c9664bf5, baseline=1.50.0-SNAPSHOT~ad6d5fef42

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (680.424 ms) : 0, 680424
BytebuddyAgent [candidate] (682.324 ms) : 0, 682324
GlobalTracer [baseline] (239.478 ms) : 0, 239478
GlobalTracer [candidate] (239.871 ms) : 0, 239871
AppSec [baseline] (54.603 ms) : 0, 54603
AppSec [candidate] (57.192 ms) : 0, 57192
Debugger [baseline] (9.912 ms) : 0, 9912
Debugger [candidate] (6.896 ms) : 0, 6896
Remote Config [baseline] (697.225 µs) : 0, 697
Remote Config [candidate] (733.567 µs) : 0, 734
Telemetry [baseline] (11.425 ms) : 0, 11425
Telemetry [candidate] (12.044 ms) : 0, 12044
section iast
BytebuddyAgent [baseline] (800.117 ms) : 0, 800117
BytebuddyAgent [candidate] (806.323 ms) : 0, 806323
GlobalTracer [baseline] (229.695 ms) : 0, 229695
GlobalTracer [candidate] (231.59 ms) : 0, 231590
IAST [baseline] (29.195 ms) : 0, 29195
IAST [candidate] (27.174 ms) : 0, 27174
AppSec [baseline] (49.912 ms) : 0, 49912
AppSec [candidate] (52.943 ms) : 0, 52943
Debugger [baseline] (5.944 ms) : 0, 5944
Debugger [candidate] (6.006 ms) : 0, 6006
Remote Config [baseline] (593.203 µs) : 0, 593
Remote Config [candidate] (582.373 µs) : 0, 582
Telemetry [baseline] (7.817 ms) : 0, 7817
Telemetry [candidate] (7.973 ms) : 0, 7973
section iast_HARDCODED_SECRET_DISABLED
BytebuddyAgent [baseline] (801.321 ms) : 0, 801321
BytebuddyAgent [candidate] (808.682 ms) : 0, 808682
GlobalTracer [baseline] (230.132 ms) : 0, 230132
GlobalTracer [candidate] (231.61 ms) : 0, 231610
IAST [baseline] (30.816 ms) : 0, 30816
IAST [candidate] (27.133 ms) : 0, 27133
AppSec [baseline] (47.621 ms) : 0, 47621
AppSec [candidate] (52.668 ms) : 0, 52668
Debugger [baseline] (5.966 ms) : 0, 5966
Debugger [candidate] (5.979 ms) : 0, 5979
Remote Config [baseline] (590.427 µs) : 0, 590
Remote Config [candidate] (580.064 µs) : 0, 580
Telemetry [baseline] (7.872 ms) : 0, 7872
Telemetry [candidate] (7.939 ms) : 0, 7939
section iast_TELEMETRY_OFF
BytebuddyAgent [baseline] (802.218 ms) : 0, 802218
BytebuddyAgent [candidate] (797.907 ms) : 0, 797907
GlobalTracer [baseline] (230.55 ms) : 0, 230550
GlobalTracer [candidate] (230.526 ms) : 0, 230526
IAST [baseline] (23.3 ms) : 0, 23300
IAST [candidate] (29.785 ms) : 0, 29785
AppSec [baseline] (55.527 ms) : 0, 55527
AppSec [candidate] (49.368 ms) : 0, 49368
Debugger [baseline] (6.026 ms) : 0, 6026
Debugger [candidate] (6.002 ms) : 0, 6002
Remote Config [baseline] (605.424 µs) : 0, 605
Remote Config [candidate] (587.099 µs) : 0, 587
Telemetry [baseline] (7.757 ms) : 0, 7757
Telemetry [candidate] (7.839 ms) : 0, 7839

Startup time reports for petclinic

gantt
    title petclinic - global startup overhead: candidate=1.50.0-SNAPSHOT~65c9664bf5, baseline=1.50.0-SNAPSHOT~ad6d5fef42

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (1.026 s) : 0, 1025883
Total [baseline] (11.089 s) : 0, 11088693
Agent [candidate] (1.021 s) : 0, 1021020
Total [candidate] (11.008 s) : 0, 11007903
section appsec
Agent [baseline] (1.162 s) : 0, 1162199
Total [baseline] (11.298 s) : 0, 11297605
Agent [candidate] (1.16 s) : 0, 1159536
Total [candidate] (11.233 s) : 0, 11233129
section iast
Agent [baseline] (1.151 s) : 0, 1151326
Total [baseline] (11.36 s) : 0, 11359638
Agent [candidate] (1.149 s) : 0, 1148591
Total [candidate] (11.344 s) : 0, 11343964
section profiling
Agent [baseline] (1.281 s) : 0, 1281270
Total [baseline] (11.372 s) : 0, 11372138
Agent [candidate] (1.27 s) : 0, 1269782
Total [candidate] (11.374 s) : 0, 11374279

baseline results

Module	Variant	Duration	Δ tracing
Agent	tracing	1.026 s	-
Agent	appsec	1.162 s	136.316 ms (13.3%)
Agent	iast	1.151 s	125.444 ms (12.2%)
Agent	profiling	1.281 s	255.387 ms (24.9%)
Total	tracing	11.089 s	-
Total	appsec	11.298 s	208.912 ms (1.9%)
Total	iast	11.36 s	270.945 ms (2.4%)
Total	profiling	11.372 s	283.445 ms (2.6%)

candidate results

Module	Variant	Duration	Δ tracing
Agent	tracing	1.021 s	-
Agent	appsec	1.16 s	138.516 ms (13.6%)
Agent	iast	1.149 s	127.571 ms (12.5%)
Agent	profiling	1.27 s	248.762 ms (24.4%)
Total	tracing	11.008 s	-
Total	appsec	11.233 s	225.226 ms (2.0%)
Total	iast	11.344 s	336.06 ms (3.1%)
Total	profiling	11.374 s	366.376 ms (3.3%)

gantt
    title petclinic - break down per module: candidate=1.50.0-SNAPSHOT~65c9664bf5, baseline=1.50.0-SNAPSHOT~ad6d5fef42

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (685.548 ms) : 0, 685548
BytebuddyAgent [candidate] (681.48 ms) : 0, 681480
GlobalTracer [baseline] (240.666 ms) : 0, 240666
GlobalTracer [candidate] (239.777 ms) : 0, 239777
AppSec [baseline] (54.695 ms) : 0, 54695
AppSec [candidate] (58.126 ms) : 0, 58126
Debugger [baseline] (8.363 ms) : 0, 8363
Debugger [candidate] (6.137 ms) : 0, 6137
Remote Config [baseline] (692.625 µs) : 0, 693
Remote Config [candidate] (711.833 µs) : 0, 712
Telemetry [baseline] (12.223 ms) : 0, 12223
Telemetry [candidate] (11.246 ms) : 0, 11246
section appsec
BytebuddyAgent [baseline] (701.26 ms) : 0, 701260
BytebuddyAgent [candidate] (698.87 ms) : 0, 698870
GlobalTracer [baseline] (236.887 ms) : 0, 236887
GlobalTracer [candidate] (237.038 ms) : 0, 237038
AppSec [baseline] (175.507 ms) : 0, 175507
AppSec [candidate] (175.421 ms) : 0, 175421
Debugger [baseline] (5.982 ms) : 0, 5982
Debugger [candidate] (5.962 ms) : 0, 5962
Remote Config [baseline] (645.758 µs) : 0, 646
Remote Config [candidate] (614.963 µs) : 0, 615
Telemetry [baseline] (7.422 ms) : 0, 7422
Telemetry [candidate] (7.294 ms) : 0, 7294
IAST [baseline] (21.828 ms) : 0, 21828
IAST [candidate] (21.614 ms) : 0, 21614
section iast
BytebuddyAgent [baseline] (803.515 ms) : 0, 803515
BytebuddyAgent [candidate] (800.748 ms) : 0, 800748
GlobalTracer [baseline] (230.488 ms) : 0, 230488
GlobalTracer [candidate] (230.449 ms) : 0, 230449
AppSec [baseline] (49.093 ms) : 0, 49093
AppSec [candidate] (53.341 ms) : 0, 53341
Debugger [baseline] (6.02 ms) : 0, 6020
Debugger [candidate] (5.909 ms) : 0, 5909
Remote Config [baseline] (613.878 µs) : 0, 614
Remote Config [candidate] (584.265 µs) : 0, 584
Telemetry [baseline] (7.867 ms) : 0, 7867
Telemetry [candidate] (7.855 ms) : 0, 7855
IAST [baseline] (28.702 ms) : 0, 28702
IAST [candidate] (26.231 ms) : 0, 26231
section profiling
ProfilingAgent [baseline] (108.505 ms) : 0, 108505
ProfilingAgent [candidate] (102.297 ms) : 0, 102297
BytebuddyAgent [baseline] (674.001 ms) : 0, 674001
BytebuddyAgent [candidate] (678.933 ms) : 0, 678933
GlobalTracer [baseline] (379.229 ms) : 0, 379229
GlobalTracer [candidate] (361.219 ms) : 0, 361219
AppSec [baseline] (54.26 ms) : 0, 54260
AppSec [candidate] (61.474 ms) : 0, 61474
Debugger [baseline] (6.071 ms) : 0, 6071
Debugger [candidate] (6.093 ms) : 0, 6093
Remote Config [baseline] (663.151 µs) : 0, 663
Remote Config [candidate] (664.772 µs) : 0, 665
Telemetry [baseline] (8.057 ms) : 0, 8057
Telemetry [candidate] (8.122 ms) : 0, 8122
Profiling [baseline] (108.531 ms) : 0, 108531
Profiling [candidate] (102.32 ms) : 0, 102320

Load

Parameters

	Baseline	Candidate
baseline_or_candidate	baseline	candidate
end_time	2025-06-03T16:28:19	2025-06-03T16:33:28
git_branch	master	smola/telemetry-log-level
git_commit_date	1746789389	1748967020
git_commit_sha	`ad6d5fe`	`65c9664`
release_version	1.50.0-SNAPSHOT~ad6d5fef42	1.50.0-SNAPSHOT~65c9664bf5
start_time	2025-06-03T16:28:01	2025-06-03T16:32:39

See matching parameters

	Baseline	Candidate
application	petclinic	petclinic
ci_job_date	1748968408	1748968408
ci_job_id	965860875	965860875
ci_pipeline_id	66832249	66832249
cpu_model	Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz	Intel(R) Xeon(R) Platinum 8259CL CPU @ 2.50GHz
kernel_version	Linux runner-bap2zmvn-project-304-concurrent-2-ltewlft8 6.8.0-1029-aws #31~22.04.1-Ubuntu SMP Thu Apr 24 21:16:18 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux	Linux runner-bap2zmvn-project-304-concurrent-2-ltewlft8 6.8.0-1029-aws #31~22.04.1-Ubuntu SMP Thu Apr 24 21:16:18 UTC 2025 x86_64 x86_64 x86_64 GNU/Linux
thresholds_or_results	results	results
variant	appsec	appsec

Summary

Found 0 performance improvements and 1 performance regressions! Performance is the same for 0 metrics, 13 unstable metrics.

scenario	Δ mean http_req_duration	Δ mean throughput	candidate mean http_req_duration	candidate mean throughput	baseline mean http_req_duration	baseline mean throughput
scenario:load:petclinic:iast	unstable [+70.188ms; +74.803ms] or [+665.264%; +709.002%]	worse [-428.233op/s; -393.491op/s] or [-91.335%; -83.925%]	83.046ms	58.000op/s	10.550ms	468.862op/s

Dacapo

AlexeyKuznetsov-DD · 2025-06-03T19:47:52Z

telemetry/src/test/groovy/datadog/telemetry/log/LogPeriodicActionTest.groovy

+  void 'log with unknown log level is normalized to DEBUG'() {
+    LogMessage logMessage
+
+    when:
+    LogCollector.get().addLogMessage("INFO", "test", null)
+    periodicAction.doIteration(telemetryService)
+
+    then:
+    1 * telemetryService.addLogMessage(_) >> { args -> logMessage = args[0] }
+    0 * _
+    logMessage.getLevel() == LogMessageLevel.DEBUG
+    logMessage.getMessage() == 'test'
+  }
+
+  void 'log with null log level is normalized to DEBUG'() {
+    LogMessage logMessage
+
+    when:
+    LogCollector.get().addLogMessage(null, "test", null)
+    periodicAction.doIteration(telemetryService)
+
+    then:
+    1 * telemetryService.addLogMessage(_) >> { args -> logMessage = args[0] }
+    0 * _
+    logMessage.getLevel() == LogMessageLevel.DEBUG
+    logMessage.getMessage() == 'test'
+  }
+


Suggestion: how about to combine into one test using where: part?

Makes sense.

Anyway, I'm holding off, as an alternative might be accepting INFO in the backend. The log level exists there, but it's currently rejected at intake.

Always set log level on telemetry logs

65c9664

smola added type: bug comp: telemetry Telemetry labels Jun 3, 2025

AlexeyKuznetsov-DD requested changes Jun 3, 2025

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Always set log level on telemetry logs #8916

Always set log level on telemetry logs #8916

Uh oh!

smola commented Jun 3, 2025 •

edited

Loading

Uh oh!

pr-commenter bot commented Jun 3, 2025

Uh oh!

AlexeyKuznetsov-DD Jun 3, 2025

Uh oh!

smola Jun 4, 2025

Uh oh!

Uh oh!

Always set log level on telemetry logs #8916

Are you sure you want to change the base?

Always set log level on telemetry logs #8916

Uh oh!

Conversation

smola commented Jun 3, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

What Does This Do

Motivation

Additional Notes

Contributor Checklist

Uh oh!

pr-commenter bot commented Jun 3, 2025

Benchmarks

Startup

Parameters

Summary

Load

Parameters

Summary

Dacapo

Uh oh!

AlexeyKuznetsov-DD Jun 3, 2025

Choose a reason for hiding this comment

Uh oh!

smola Jun 4, 2025

Choose a reason for hiding this comment

Uh oh!

Uh oh!

smola commented Jun 3, 2025 •

edited

Loading