Skip to content

Improved logging using placeholders - #4619

Merged
DDJavierSantos merged 4 commits into
masterfrom
jsantos/debug_sensitive_info_audit
Aug 10, 2023
Merged

Improved logging using placeholders#4619
DDJavierSantos merged 4 commits into
masterfrom
jsantos/debug_sensitive_info_audit

Conversation

@DDJavierSantos

@DDJavierSantos DDJavierSantos commented Jan 30, 2023 •
edited by smola
Loading

Copy link
Copy Markdown
Contributor

What Does This Do

debug, error and warn logging statements that report both a resource and an exception have been changed so they use placeholders instead of string operations.

Motivation

Exception reports filed by DDLogger will be sent to our servers using the telemetry API. If the message is composed using placeholders instead of string operations, the placeholders will not be substituted when sending this information over the wire to the telemetry API. This will make sure we don't send any sensitive information to the telemetry service once the telemetry API is merged.

Additional Notes

This changes are related to the new telemetry functionality implemented by #4521

smola
smola requested changes Jan 30, 2023
View reviewed changes
Comment thread ...ent/agent-bootstrap/src/main/java/datadog/trace/bootstrap/blocking/BlockingActionHelper.java Outdated
@DDJavierSantos DDJavierSantos changed the title Removing some statements that log sensitive information Improved logging using placeholders Jan 30, 2023
smola
smola reviewed Jan 30, 2023
View reviewed changes
Comment thread dd-java-agent/agent-bootstrap/src/main/java/datadog/trace/bootstrap/Agent.java Outdated
Comment thread dd-java-agent/agent-profiling/src/main/java/com/datadog/profiling/agent/ProfilingAgent.java
Comment thread ...-tests/jboss-modules/src/main/java/datadog/smoketest/jbossmodules/common/ServiceSupport.java Outdated
Comment thread dd-trace-core/src/main/java/datadog/trace/core/CoreTracer.java Outdated
@smola smola added tag: no release notes Changes to exclude from release notes type: refactoring labels Jan 30, 2023
@DDJavierSantos
DDJavierSantos marked this pull request as ready for review February 2, 2023 09:49
@DDJavierSantos
DDJavierSantos requested review from ojung and removed request for a team February 2, 2023 09:49
@DDJavierSantos
# This is a combination of 2 commits.
4f22d2b 
# This is the 1st commit message:

Removing statements that log sensitive information and exceptions since they would be sent over the wire by the telemetry logging API

Changing statements so they use placeholders instead of adding strings

# This is the commit message #2:

linter applied

Update dd-smoke-tests/jboss-modules/src/main/java/datadog/smoketest/jbossmodules/common/ServiceSupport.java

Co-authored-by: Santiago M. Mola <santiago.mola@datadoghq.com>

processing PR comments

Processing PR comments

This statement doesn't need the placeholder
@DDJavierSantos
rebased
c0b2336
@DDJavierSantos
DDJavierSantos force-pushed the jsantos/debug_sensitive_info_audit branch from 88f1f3b to c0b2336 Compare August 9, 2023 16:18
@pr-commenter

This comment has been minimized.

Sign in to view
@pr-commenter

This comment has been minimized.

Sign in to view
@pr-commenter

pr-commenter Bot commented Aug 10, 2023

Copy link
Copy Markdown

Benchmarks

Startup

Parameters

Baseline Candidate
commit 1.20.0-SNAPSHOT~8c080b4046 1.20.0-SNAPSHOT~2803e37468
config baseline candidate
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
module Agent Agent
parent None None
variant appsec appsec

Summary

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

scenario Δ mean execution_time candidate mean execution_time baseline mean execution_time
scenario:insecure-bank:iast:IAST better
[-1142.152µs; -578.473µs] or [-8.082%; -4.093%]		 13.271ms 14.132ms
scenario:petclinic:iast:IAST better
[-840.160µs; -517.555µs] or [-6.019%; -3.708%]		 13.280ms 13.959ms
Startup time reports for petclinic 
gantt
    title petclinic - global startup overhead: candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (990.602 ms) : 0, 990602
Total [baseline] (9.218 s) : 0, 9217796
Agent [candidate] (985.255 ms) : 0, 985255
Total [candidate] (9.217 s) : 0, 9216589
section appsec
Agent [baseline] (1.069 s) : 0, 1068602
Total [baseline] (9.234 s) : 0, 9234353
Agent [candidate] (1.07 s) : 0, 1070226
Total [candidate] (9.279 s) : 0, 9278597
section iast
Agent [baseline] (1.084 s) : 0, 1083553
Total [baseline] (9.439 s) : 0, 9439344
Agent [candidate] (1.083 s) : 0, 1083011
Total [candidate] (9.425 s) : 0, 9424868
section profiling
Agent [baseline] (1.153 s) : 0, 1153133
Total [baseline] (9.471 s) : 0, 9471181
Agent [candidate] (1.155 s) : 0, 1155092
Total [candidate] (9.485 s) : 0, 9485044
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 990.602 ms -
Agent appsec 1.069 s 78.0 ms (7.9%)
Agent iast 1.084 s 92.951 ms (9.4%)
Agent profiling 1.153 s 162.53 ms (16.4%)
Total tracing 9.218 s -
Total appsec 9.234 s 16.556 ms (0.2%)
Total iast 9.439 s 221.547 ms (2.4%)
Total profiling 9.471 s 253.384 ms (2.7%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 985.255 ms -
Agent appsec 1.07 s 84.971 ms (8.6%)
Agent iast 1.083 s 97.756 ms (9.9%)
Agent profiling 1.155 s 169.837 ms (17.2%)
Total tracing 9.217 s -
Total appsec 9.279 s 62.008 ms (0.7%)
Total iast 9.425 s 208.28 ms (2.3%)
Total profiling 9.485 s 268.456 ms (2.9%) 
gantt
    title petclinic - break down per module: candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (613.735 ms) : 0, 613735
BytebuddyAgent [candidate] (610.357 ms) : 0, 610357
GlobalTracer [baseline] (285.801 ms) : 0, 285801
GlobalTracer [candidate] (284.36 ms) : 0, 284360
AppSec [baseline] (50.409 ms) : 0, 50409
AppSec [candidate] (50.106 ms) : 0, 50106
Remote Config [baseline] (682.155 µs) : 0, 682
Remote Config [candidate] (676.257 µs) : 0, 676
Telemetry [baseline] (5.492 ms) : 0, 5492
Telemetry [candidate] (5.409 ms) : 0, 5409
section appsec
BytebuddyAgent [baseline] (609.834 ms) : 0, 609834
BytebuddyAgent [candidate] (610.468 ms) : 0, 610468
GlobalTracer [baseline] (283.687 ms) : 0, 283687
GlobalTracer [candidate] (284.621 ms) : 0, 284621
AppSec [baseline] (134.898 ms) : 0, 134898
AppSec [candidate] (134.984 ms) : 0, 134984
Remote Config [baseline] (718.527 µs) : 0, 719
Remote Config [candidate] (719.743 µs) : 0, 720
Telemetry [baseline] (5.181 ms) : 0, 5181
Telemetry [candidate] (5.138 ms) : 0, 5138
section iast
BytebuddyAgent [baseline] (711.5 ms) : 0, 711500
BytebuddyAgent [candidate] (711.512 ms) : 0, 711512
GlobalTracer [baseline] (270.608 ms) : 0, 270608
GlobalTracer [candidate] (270.639 ms) : 0, 270639
AppSec [baseline] (47.033 ms) : 0, 47033
AppSec [candidate] (47.087 ms) : 0, 47087
Remote Config [baseline] (647.945 µs) : 0, 648
Remote Config [candidate] (642.43 µs) : 0, 642
Telemetry [baseline] (5.483 ms) : 0, 5483
Telemetry [candidate] (5.586 ms) : 0, 5586
IAST [baseline] (13.959 ms) : 0, 13959
IAST [candidate] (13.28 ms) : 0, 13280
section profiling
BytebuddyAgent [baseline] (621.202 ms) : 0, 621202
BytebuddyAgent [candidate] (622.283 ms) : 0, 622283
GlobalTracer [baseline] (347.605 ms) : 0, 347605
GlobalTracer [candidate] (349.286 ms) : 0, 349286
AppSec [baseline] (49.154 ms) : 0, 49154
AppSec [candidate] (49.183 ms) : 0, 49183
Remote Config [baseline] (647.775 µs) : 0, 648
Remote Config [candidate] (650.581 µs) : 0, 651
Telemetry [baseline] (5.349 ms) : 0, 5349
Telemetry [candidate] (5.314 ms) : 0, 5314
ProfilingAgent [baseline] (76.548 ms) : 0, 76548
ProfilingAgent [candidate] (75.546 ms) : 0, 75546
Profiling [baseline] (76.572 ms) : 0, 76572
Profiling [candidate] (75.571 ms) : 0, 75571
Loading
Startup time reports for insecure-bank 
gantt
    title insecure-bank - global startup overhead: candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046

    dateFormat X
    axisFormat %s
section tracing
Agent [baseline] (996.916 ms) : 0, 996916
Total [baseline] (8.704 s) : 0, 8703998
Agent [candidate] (984.635 ms) : 0, 984635
Total [candidate] (8.657 s) : 0, 8657124
section appsec
Agent [baseline] (1.068 s) : 0, 1068312
Total [baseline] (8.711 s) : 0, 8710891
Agent [candidate] (1.07 s) : 0, 1069576
Total [candidate] (8.731 s) : 0, 8730561
section iast
Agent [baseline] (1.092 s) : 0, 1092159
Total [baseline] (9.175 s) : 0, 9174814
Agent [candidate] (1.085 s) : 0, 1085031
Total [candidate] (9.163 s) : 0, 9162670
section profiling
Agent [baseline] (1.154 s) : 0, 1153572
Total [baseline] (8.885 s) : 0, 8884817
Agent [candidate] (1.153 s) : 0, 1152826
Total [candidate] (8.864 s) : 0, 8863536
Loading
  • baseline results
Module Variant Duration Δ tracing
Agent tracing 996.916 ms -
Agent appsec 1.068 s 71.397 ms (7.2%)
Agent iast 1.092 s 95.243 ms (9.6%)
Agent profiling 1.154 s 156.656 ms (15.7%)
Total tracing 8.704 s -
Total appsec 8.711 s 6.893 ms (0.1%)
Total iast 9.175 s 470.816 ms (5.4%)
Total profiling 8.885 s 180.82 ms (2.1%)
  • candidate results
Module Variant Duration Δ tracing
Agent tracing 984.635 ms -
Agent appsec 1.07 s 84.941 ms (8.6%)
Agent iast 1.085 s 100.396 ms (10.2%)
Agent profiling 1.153 s 168.19 ms (17.1%)
Total tracing 8.657 s -
Total appsec 8.731 s 73.437 ms (0.8%)
Total iast 9.163 s 505.546 ms (5.8%)
Total profiling 8.864 s 206.412 ms (2.4%) 
gantt
    title insecure-bank - break down per module: candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046

    dateFormat X
    axisFormat %s
section tracing
BytebuddyAgent [baseline] (617.928 ms) : 0, 617928
BytebuddyAgent [candidate] (609.982 ms) : 0, 609982
GlobalTracer [baseline] (287.852 ms) : 0, 287852
GlobalTracer [candidate] (283.875 ms) : 0, 283875
AppSec [baseline] (50.294 ms) : 0, 50294
AppSec [candidate] (50.44 ms) : 0, 50440
Remote Config [baseline] (671.556 µs) : 0, 672
Remote Config [candidate] (659.782 µs) : 0, 660
Telemetry [baseline] (5.449 ms) : 0, 5449
Telemetry [candidate] (5.389 ms) : 0, 5389
section appsec
BytebuddyAgent [baseline] (609.452 ms) : 0, 609452
BytebuddyAgent [candidate] (610.099 ms) : 0, 610099
GlobalTracer [baseline] (283.769 ms) : 0, 283769
GlobalTracer [candidate] (284.106 ms) : 0, 284106
AppSec [baseline] (134.917 ms) : 0, 134917
AppSec [candidate] (135.255 ms) : 0, 135255
Remote Config [baseline] (722.393 µs) : 0, 722
Remote Config [candidate] (722.855 µs) : 0, 723
Telemetry [baseline] (5.123 ms) : 0, 5123
Telemetry [candidate] (5.138 ms) : 0, 5138
section iast
BytebuddyAgent [baseline] (716.995 ms) : 0, 716995
BytebuddyAgent [candidate] (712.831 ms) : 0, 712831
GlobalTracer [baseline] (272.505 ms) : 0, 272505
GlobalTracer [candidate] (271.21 ms) : 0, 271210
AppSec [baseline] (47.671 ms) : 0, 47671
AppSec [candidate] (47.255 ms) : 0, 47255
Remote Config [baseline] (654.081 µs) : 0, 654
Remote Config [candidate] (635.202 µs) : 0, 635
Telemetry [baseline] (5.647 ms) : 0, 5647
Telemetry [candidate] (5.506 ms) : 0, 5506
IAST [baseline] (14.132 ms) : 0, 14132
IAST [candidate] (13.271 ms) : 0, 13271
section profiling
BytebuddyAgent [baseline] (621.674 ms) : 0, 621674
BytebuddyAgent [candidate] (621.723 ms) : 0, 621723
GlobalTracer [baseline] (348.665 ms) : 0, 348665
GlobalTracer [candidate] (348.913 ms) : 0, 348913
AppSec [baseline] (49.149 ms) : 0, 49149
AppSec [candidate] (49.225 ms) : 0, 49225
Remote Config [baseline] (658.144 µs) : 0, 658
Remote Config [candidate] (648.421 µs) : 0, 648
Telemetry [baseline] (5.364 ms) : 0, 5364
Telemetry [candidate] (5.341 ms) : 0, 5341
ProfilingAgent [baseline] (75.302 ms) : 0, 75302
ProfilingAgent [candidate] (74.211 ms) : 0, 74211
Profiling [baseline] (75.327 ms) : 0, 75327
Profiling [candidate] (74.235 ms) : 0, 74235
Loading

Load

Parameters

Baseline Candidate
commit 1.20.0-SNAPSHOT~8c080b4046 1.20.0-SNAPSHOT~2803e37468
config baseline candidate
end_time 2023-08-10T14:21:36 2023-08-10T14:39:42
start_time 2023-08-10T14:21:19 2023-08-10T14:39:25
See matching parameters
Baseline Candidate
application insecure-bank insecure-bank
variant appsec appsec

Summary

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

Request duration reports for petclinic 
gantt
    title petclinic - request duration [CI 0.99] : candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046
    dateFormat X
    axisFormat %s
section baseline
no_agent (1.336 ms) : 1317, 1355
.   : milestone, 1336,
appsec (1.687 ms) : 1662, 1711
.   : milestone, 1687,
iast (1.436 ms) : 1411, 1461
.   : milestone, 1436,
profiling (1.493 ms) : 1467, 1519
.   : milestone, 1493,
tracing (1.45 ms) : 1426, 1474
.   : milestone, 1450,
section candidate
no_agent (1.327 ms) : 1308, 1346
.   : milestone, 1327,
appsec (1.678 ms) : 1654, 1702
.   : milestone, 1678,
iast (1.451 ms) : 1426, 1476
.   : milestone, 1451,
profiling (1.461 ms) : 1436, 1485
.   : milestone, 1461,
tracing (1.45 ms) : 1425, 1475
.   : milestone, 1450,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.336 ms [1.317 ms, 1.355 ms] -
appsec 1.687 ms [1.662 ms, 1.711 ms] 351.331 µs (26.3%)
iast 1.436 ms [1.411 ms, 1.461 ms] 100.41 µs (7.5%)
profiling 1.493 ms [1.467 ms, 1.519 ms] 157.503 µs (11.8%)
tracing 1.45 ms [1.426 ms, 1.474 ms] 114.601 µs (8.6%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 1.327 ms [1.308 ms, 1.346 ms] -
appsec 1.678 ms [1.654 ms, 1.702 ms] 350.825 µs (26.4%)
iast 1.451 ms [1.426 ms, 1.476 ms] 123.695 µs (9.3%)
profiling 1.461 ms [1.436 ms, 1.485 ms] 133.56 µs (10.1%)
tracing 1.45 ms [1.425 ms, 1.475 ms] 122.908 µs (9.3%)
Request duration reports for insecure-bank 
gantt
    title insecure-bank - request duration [CI 0.99] : candidate=1.20.0-SNAPSHOT~2803e37468, baseline=1.20.0-SNAPSHOT~8c080b4046
    dateFormat X
    axisFormat %s
section baseline
no_agent (361.296 µs) : 341, 381
.   : milestone, 361,
appsec (648.067 µs) : 628, 668
.   : milestone, 648,
iast (462.872 µs) : 442, 484
.   : milestone, 463,
iast_FULL (520.415 µs) : 500, 541
.   : milestone, 520,
iast_INACTIVE (441.026 µs) : 419, 463
.   : milestone, 441,
profiling (442.202 µs) : 420, 464
.   : milestone, 442,
tracing (439.832 µs) : 419, 461
.   : milestone, 440,
section candidate
no_agent (363.526 µs) : 342, 385
.   : milestone, 364,
appsec (665.498 µs) : 644, 687
.   : milestone, 665,
iast (464.839 µs) : 443, 486
.   : milestone, 465,
iast_FULL (520.109 µs) : 499, 541
.   : milestone, 520,
iast_INACTIVE (439.088 µs) : 417, 461
.   : milestone, 439,
profiling (437.316 µs) : 416, 459
.   : milestone, 437,
tracing (433.755 µs) : 413, 454
.   : milestone, 434,
Loading
  • baseline results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 361.296 µs [341.174 µs, 381.417 µs] -
appsec 648.067 µs [628.237 µs, 667.897 µs] 286.771 µs (79.4%)
iast 462.872 µs [441.911 µs, 483.833 µs] 101.576 µs (28.1%)
iast_FULL 520.415 µs [499.581 µs, 541.248 µs] 159.119 µs (44.0%)
iast_INACTIVE 441.026 µs [419.243 µs, 462.808 µs] 79.73 µs (22.1%)
profiling 442.202 µs [420.368 µs, 464.036 µs] 80.906 µs (22.4%)
tracing 439.832 µs [419.012 µs, 460.651 µs] 78.536 µs (21.7%)
  • candidate results
Variant Request duration [CI 0.99] Δ no_agent
no_agent 363.526 µs [342.019 µs, 385.034 µs] -
appsec 665.498 µs [643.631 µs, 687.364 µs] 301.971 µs (83.1%)
iast 464.839 µs [443.492 µs, 486.187 µs] 101.313 µs (27.9%)
iast_FULL 520.109 µs [499.377 µs, 540.84 µs] 156.582 µs (43.1%)
iast_INACTIVE 439.088 µs [417.015 µs, 461.16 µs] 75.561 µs (20.8%)
profiling 437.316 µs [415.633 µs, 458.999 µs] 73.79 µs (20.3%)
tracing 433.755 µs [413.115 µs, 454.395 µs] 70.228 µs (19.3%)

@DDJavierSantos
DDJavierSantos merged commit a748d30 into master Aug 10, 2023
@DDJavierSantos
DDJavierSantos deleted the jsantos/debug_sensitive_info_audit branch August 10, 2023 15:22
@github-actions github-actions Bot added this to the 1.20.0 milestone Aug 10, 2023
jpbempel added a commit that referenced this pull request Aug 21, 2023
@jpbempel
fix log error throwable
a37bb38 
Following #4619, the exception was not logged as before.
@jpbempel jpbempel mentioned this pull request Aug 21, 2023
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@bantonsson bantonsson bantonsson left review comments
@jpbempel jpbempel jpbempel approved these changes
@smola smola smola approved these changes
@ValentinZakharov ValentinZakharov Awaiting requested review from ValentinZakharov
@ojung ojung Awaiting requested review from ojung ojung is a code owner automatically assigned from DataDog/debugger-java
+1 more reviewer
@richardstartin richardstartin richardstartin approved these changes
Reviewers whose approvals may not affect merge requirements

Assignees

No one assigned

Labels

tag: no release notes Changes to exclude from release notes type: refactoring

Projects

None yet

Milestone

1.20.0

Development

Successfully merging this pull request may close these issues.

5 participants

@DDJavierSantos @smola @bantonsson @jpbempel @richardstartin