change some log levels from `info` to `debug` #6651

lucaspimentel · 2025-02-10T20:09:21Z

Summary of changes

Change the log level of several messages from info to debug...

Reason for change

...to reduce log spam.

Implementation details

Change the log levels.

Test coverage

N/A

Other details

N/A

andrewlock · 2025-02-10T20:55:03Z

Execution-Time Benchmarks Report ⏱️

Execution-time results for samples comparing the following branches/commits:

Execution-time benchmarks measure the whole time it takes to execute a program. And are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are shown in red. The following thresholds were used for comparing the execution times:

Welch test with statistical test for significance of 5%
Only results indicating a difference greater than 5% and 5 ms are considered.

Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard.

Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph).

gantt
    title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (69ms)  : 66, 73
     .   : milestone, 69,
    master - mean (69ms)  : 66, 73
     .   : milestone, 69,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (994ms)  : 972, 1016
     .   : milestone, 994,
    master - mean (993ms)  : 972, 1013
     .   : milestone, 993,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (103ms)  : 101, 105
     .   : milestone, 103,
    master - mean (102ms)  : 100, 105
     .   : milestone, 102,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (673ms)  : 657, 688
     .   : milestone, 673,
    master - mean (677ms)  : 662, 692
     .   : milestone, 677,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (90ms)  : 88, 92
     .   : milestone, 90,
    master - mean (90ms)  : 87, 92
     .   : milestone, 90,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (634ms)  : 617, 651
     .   : milestone, 634,
    master - mean (629ms)  : 613, 646
     .   : milestone, 629,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (190ms)  : 186, 195
     .   : milestone, 190,
    master - mean (190ms)  : 186, 195
     .   : milestone, 190,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (1,102ms)  : 1069, 1135
     .   : milestone, 1102,
    master - mean (1,103ms)  : 1075, 1131
     .   : milestone, 1103,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (270ms)  : 266, 274
     .   : milestone, 270,
    master - mean (270ms)  : 266, 274
     .   : milestone, 270,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (863ms)  : 836, 890
     .   : milestone, 863,
    master - mean (860ms)  : 835, 885
     .   : milestone, 860,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6651) - mean (261ms)  : 257, 265
     .   : milestone, 261,
    master - mean (261ms)  : 257, 265
     .   : milestone, 261,

    section CallTarget+Inlining+NGEN
    This PR (6651) - mean (844ms)  : 816, 871
     .   : milestone, 844,
    master - mean (841ms)  : 814, 868
     .   : milestone, 841,

andrewlock · 2025-02-10T21:22:46Z

Benchmarks Report for tracer 🐌

Benchmarks for #6651 compared to master:

1 benchmarks are faster, with geometric mean 1.161
All benchmarks have the same allocations

The following thresholds were used for comparing the benchmark speeds:

Mann–Whitney U test with statistical test for significance of 5%
Only results indicating a difference greater than 10% and 0.3 ns are considered.

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.ActivityBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`StartStopWithChild`	net6.0	7.88μs	44ns	282ns	0.0153	0.00765	0	5.6 KB
master	`StartStopWithChild`	netcoreapp3.1	9.94μs	46.7ns	198ns	0.015	0.01	0	5.81 KB
master	`StartStopWithChild`	net472	15.9μs	45.9ns	178ns	1.04	0.311	0.104	6.21 KB
#6651	`StartStopWithChild`	net6.0	8.05μs	44ns	323ns	0.0157	0.00392	0	5.61 KB
#6651	`StartStopWithChild`	netcoreapp3.1	10μs	56.1ns	381ns	0.0147	0.0049	0	5.81 KB
#6651	`StartStopWithChild`	net472	16.1μs	35.6ns	133ns	1.04	0.318	0.0979	6.21 KB

Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	486μs	246ns	921ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	651μs	349ns	1.31μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	857μs	473ns	1.83μs	0.425	3.3 KB
#6651	`WriteAndFlushEnrichedTraces`	net6.0	468μs	276ns	1.07μs	0	2.7 KB
#6651	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	665μs	211ns	817ns	0	2.7 KB
#6651	`WriteAndFlushEnrichedTraces`	net472	833μs	543ns	2.1μs	0.414	3.3 KB

Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	126μs	620ns	2.48μs	0.192	14.47 KB
master	`SendRequest`	netcoreapp3.1	145μs	283ns	1.09μs	0.213	17.28 KB
master	`SendRequest`	net472	0.00409ns	0.00151ns	0.00585ns	0	0 b
#6651	`SendRequest`	net6.0	132μs	371ns	1.44μs	0.199	14.47 KB
#6651	`SendRequest`	netcoreapp3.1	144μs	613ns	2.37μs	0.212	17.27 KB
#6651	`SendRequest`	net472	0ns	0ns	0ns	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	588μs	3.5μs	34.5μs	0.568	0	0	41.55 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	690μs	3.92μs	28μs	0.353	0	0	41.79 KB
master	`WriteAndFlushEnrichedTraces`	net472	869μs	4.39μs	21μs	8.45	2.53	0.422	53.34 KB
#6651	`WriteAndFlushEnrichedTraces`	net6.0	577μs	2.89μs	14.8μs	0.59	0	0	41.74 KB
#6651	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	648μs	3.24μs	14.9μs	0.324	0	0	41.71 KB
#6651	`WriteAndFlushEnrichedTraces`	net472	867μs	4μs	18.7μs	8.33	2.5	0.417	53.29 KB

Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`ExecuteNonQuery`	net6.0	1.38μs	1.25ns	4.68ns	0.0144	0	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.71μs	5.54ns	21.4ns	0.0135	0	1.02 KB
master	`ExecuteNonQuery`	net472	2.11μs	3.24ns	12.5ns	0.156	0.00106	987 B
#6651	`ExecuteNonQuery`	net6.0	1.32μs	0.817ns	3.17ns	0.0145	0	1.02 KB
#6651	`ExecuteNonQuery`	netcoreapp3.1	1.87μs	1.63ns	6.11ns	0.0139	0	1.02 KB
#6651	`ExecuteNonQuery`	net472	2.1μs	1.63ns	6.32ns	0.156	0.00104	987 B

Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.3μs	0.468ns	1.75ns	0.0136	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.55μs	1.94ns	7.53ns	0.0132	976 B
master	`CallElasticsearch`	net472	2.56μs	1.75ns	6.76ns	0.158	995 B
master	`CallElasticsearchAsync`	net6.0	1.3μs	0.569ns	2.13ns	0.0134	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.64μs	0.743ns	2.88ns	0.0139	1.02 KB
master	`CallElasticsearchAsync`	net472	2.65μs	1.91ns	7.39ns	0.166	1.05 KB
#6651	`CallElasticsearch`	net6.0	1.19μs	1.31ns	4.92ns	0.0138	976 B
#6651	`CallElasticsearch`	netcoreapp3.1	1.58μs	1.04ns	3.91ns	0.0134	976 B
#6651	`CallElasticsearch`	net472	2.54μs	1.22ns	4.58ns	0.158	995 B
#6651	`CallElasticsearchAsync`	net6.0	1.3μs	2.61ns	10.1ns	0.013	952 B
#6651	`CallElasticsearchAsync`	netcoreapp3.1	1.68μs	0.794ns	2.97ns	0.0142	1.02 KB
#6651	`CallElasticsearchAsync`	net472	2.61μs	1.11ns	4.16ns	0.167	1.05 KB

Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.4μs	0.507ns	1.9ns	0.0134	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.71μs	2.41ns	9.03ns	0.0131	952 B
master	`ExecuteAsync`	net472	1.84μs	0.885ns	3.43ns	0.145	915 B
#6651	`ExecuteAsync`	net6.0	1.35μs	0.328ns	1.18ns	0.0136	952 B
#6651	`ExecuteAsync`	netcoreapp3.1	1.64μs	0.742ns	2.87ns	0.013	952 B
#6651	`ExecuteAsync`	net472	1.82μs	0.552ns	2.07ns	0.144	915 B

Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	4.38μs	3.2ns	12.4ns	0.033	2.31 KB
master	`SendAsync`	netcoreapp3.1	5.28μs	1.25ns	4.51ns	0.0368	2.85 KB
master	`SendAsync`	net472	7.42μs	3.12ns	12.1ns	0.493	3.12 KB
#6651	`SendAsync`	net6.0	4.36μs	2.13ns	7.69ns	0.0328	2.31 KB
#6651	`SendAsync`	netcoreapp3.1	5.22μs	4.82ns	18ns	0.039	2.85 KB
#6651	`SendAsync`	net472	7.54μs	10.7ns	41.5ns	0.493	3.12 KB

Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.58μs	0.738ns	2.56ns	0.0229	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.14μs	1.04ns	4.03ns	0.0224	1.64 KB
master	`EnrichedLog`	net472	2.59μs	0.949ns	3.68ns	0.249	1.57 KB
#6651	`EnrichedLog`	net6.0	1.47μs	0.805ns	3.01ns	0.0229	1.64 KB
#6651	`EnrichedLog`	netcoreapp3.1	2.2μs	1.13ns	4.23ns	0.0221	1.64 KB
#6651	`EnrichedLog`	net472	2.63μs	1.14ns	4.26ns	0.249	1.57 KB

Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EnrichedLog`	net6.0	113μs	94.8ns	367ns	0.0563	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	115μs	129ns	498ns	0.0572	0	4.28 KB
master	`EnrichedLog`	net472	151μs	111ns	429ns	0.678	0.226	4.46 KB
#6651	`EnrichedLog`	net6.0	113μs	133ns	515ns	0.0565	0	4.28 KB
#6651	`EnrichedLog`	netcoreapp3.1	117μs	138ns	534ns	0.0588	0	4.28 KB
#6651	`EnrichedLog`	net472	151μs	121ns	468ns	0.684	0.228	4.46 KB

Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	3μs	0.654ns	2.53ns	0.0312	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.32μs	1.25ns	4.86ns	0.0304	2.2 KB
master	`EnrichedLog`	net472	4.86μs	2.4ns	9.28ns	0.32	2.02 KB
#6651	`EnrichedLog`	net6.0	3.16μs	1.24ns	4.79ns	0.03	2.2 KB
#6651	`EnrichedLog`	netcoreapp3.1	4.02μs	10.1ns	39.1ns	0.0299	2.2 KB
#6651	`EnrichedLog`	net472	4.92μs	1.22ns	4.58ns	0.319	2.02 KB

Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.43μs	2.65ns	10.3ns	0.0158	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.74μs	1.13ns	4.39ns	0.0157	1.14 KB
master	`SendReceive`	net472	1.98μs	1.55ns	5.99ns	0.183	1.16 KB
#6651	`SendReceive`	net6.0	1.34μs	1.01ns	3.9ns	0.016	1.14 KB
#6651	`SendReceive`	netcoreapp3.1	1.82μs	1.33ns	5.15ns	0.0145	1.14 KB
#6651	`SendReceive`	net472	2.05μs	3.02ns	11.7ns	0.183	1.16 KB

Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.82μs	1.15ns	4.46ns	0.0226	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	3.96μs	1.32ns	5.11ns	0.0218	1.65 KB
master	`EnrichedLog`	net472	4.45μs	11.6ns	44.9ns	0.323	2.04 KB
#6651	`EnrichedLog`	net6.0	2.88μs	1.58ns	6.11ns	0.0217	1.6 KB
#6651	`EnrichedLog`	netcoreapp3.1	3.8μs	3.11ns	12.1ns	0.0228	1.65 KB
#6651	`EnrichedLog`	net472	4.34μs	2.22ns	8ns	0.323	2.04 KB

Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #6651

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑net6.0	1.161	557.93	480.57

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	401ns	0.376ns	1.46ns	0.00817	576 B
master	`StartFinishSpan`	netcoreapp3.1	554ns	0.986ns	3.82ns	0.00783	576 B
master	`StartFinishSpan`	net472	630ns	1.05ns	4.07ns	0.0917	578 B
master	`StartFinishScope`	net6.0	558ns	0.645ns	2.41ns	0.0096	696 B
master	`StartFinishScope`	netcoreapp3.1	674ns	1.26ns	4.87ns	0.00927	696 B
master	`StartFinishScope`	net472	873ns	1.04ns	3.88ns	0.105	658 B
#6651	`StartFinishSpan`	net6.0	396ns	0.507ns	1.96ns	0.00815	576 B
#6651	`StartFinishSpan`	netcoreapp3.1	544ns	0.806ns	3.12ns	0.00784	576 B
#6651	`StartFinishSpan`	net472	626ns	1.31ns	5.06ns	0.0917	578 B
#6651	`StartFinishScope`	net6.0	480ns	0.47ns	1.76ns	0.00976	696 B
#6651	`StartFinishScope`	netcoreapp3.1	708ns	1.17ns	4.55ns	0.00926	696 B
#6651	`StartFinishScope`	net472	798ns	1.7ns	6.58ns	0.104	658 B

Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	668ns	0.931ns	3.61ns	0.00974	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	928ns	1.55ns	6ns	0.00929	696 B
master	`RunOnMethodBegin`	net472	1.04μs	1.64ns	6.36ns	0.105	658 B
#6651	`RunOnMethodBegin`	net6.0	607ns	0.991ns	3.84ns	0.00971	696 B
#6651	`RunOnMethodBegin`	netcoreapp3.1	912ns	1.13ns	4.39ns	0.00959	696 B
#6651	`RunOnMethodBegin`	net472	1.15μs	2.06ns	7.97ns	0.104	658 B

lucaspimentel · 2025-02-10T21:34:00Z

Merge activity

Feb 10, 4:34 PM EST: A user merged this pull request with Graphite.

change log from info to debug

29f2a63

lucaspimentel added the area:native-library Automatic instrumentation native C++ code (Datadog.Trace.ClrProfiler.Native) label Feb 10, 2025

change log level to debug

dc34490

lucaspimentel changed the title ~~change log level from info to debug: Method enqueued for ReJIT for...~~ change some log levels from info to debug in rejit_preprocessor.cpp Feb 10, 2025

change log level (ServiceFabric)

e83eed3

lucaspimentel changed the title ~~change some log levels from info to debug in rejit_preprocessor.cpp~~ change some log levels from info to debug Feb 10, 2025

lucaspimentel marked this pull request as ready for review February 10, 2025 20:17

lucaspimentel requested a review from a team as a code owner February 10, 2025 20:17

link04 approved these changes Feb 10, 2025

View reviewed changes

zacharycmontoya approved these changes Feb 10, 2025

View reviewed changes

lucaspimentel merged commit 1ed37e8 into master Feb 10, 2025
140 of 146 checks passed

lucaspimentel deleted the lpimentel/log-info-to-debug branch February 10, 2025 21:34

github-actions bot added this to the vNext-v3 milestone Feb 10, 2025

andrewlock added the type:refactor label Feb 11, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

change some log levels from `info` to `debug` #6651

change some log levels from `info` to `debug` #6651

lucaspimentel commented Feb 10, 2025 •

edited

Loading

andrewlock commented Feb 10, 2025

andrewlock commented Feb 10, 2025

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6651

Raw results

Raw results

lucaspimentel commented Feb 10, 2025

change some log levels from info to debug #6651

change some log levels from info to debug #6651

Conversation

lucaspimentel commented Feb 10, 2025 • edited Loading

Summary of changes

Reason for change

Implementation details

Test coverage

Other details

andrewlock commented Feb 10, 2025

Execution-Time Benchmarks Report ⏱️

andrewlock commented Feb 10, 2025

Benchmarks Report for tracer 🐌

Benchmark details

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6651

Raw results

Raw results

lucaspimentel commented Feb 10, 2025

Merge activity

change some log levels from `info` to `debug` #6651

change some log levels from `info` to `debug` #6651

lucaspimentel commented Feb 10, 2025 •

edited

Loading