Skip to content

Adding Tags Data to Span Started Logs#3377

Merged
link04 merged 6 commits into
masterfrom
maximo/logging-span-details-first
Oct 21, 2022
Merged

Adding Tags Data to Span Started Logs#3377
link04 merged 6 commits into
masterfrom
maximo/logging-span-details-first

Conversation

@link04

@link04 link04 commented Oct 21, 2022

Copy link
Copy Markdown
Contributor

Summary of changes

Added the Span Tags and Tags type details as part of the startup logs so we can have an idea of the span type when it gets started.

Reason for change

This way we'll have a way to try identifying spans that for some reason may not be getting closed, previously the started span log only included the span related ids.

Implementation details

Added the log into an if statement to log only if Debug mode is enable, similar to what is done for span closed logs.

Test coverage

I built the MSI for the tracer and was then able to see the new log files, example log after:

2022-10-20 13:33:27.422 -04:00 [DBG] Span started: [s_id: 6309444753191957727, p_id: null, t_id: 1350847350902100029] 
with Tags: [component (tag):aspnet_core,span.kind (tag):server,], Tags Type:[Datadog.Trace.Tagging.AspNetCoreEndpointTags]) 
{ MachineName: ".", Process: "[23020 sample-web-app]", AppDomain: "[1 sample-web-app]",
AssemblyLoadContext: "\"\" Datadog.Trace.ClrProfiler.Managed.Loader.ManagedProfilerAssemblyLoadContext #1", TracerVersion: "2.18.0.0" }

@link04
link04 requested a review from a team as a code owner October 21, 2022 00:03
@github-actions github-actions Bot added the area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) label Oct 21, 2022
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
andrewlock
andrewlock approved these changes Oct 21, 2022
View reviewed changes

@andrewlock andrewlock left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

LGTM, I think this will be very useful 👍

pierotibou
pierotibou approved these changes Oct 21, 2022
View reviewed changes

@pierotibou pierotibou left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Thanks a lot for doing this

tonyredondo
tonyredondo approved these changes Oct 21, 2022
View reviewed changes
Comment thread tracer/src/Datadog.Trace/Span.cs Outdated
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

andrewlock commented Oct 21, 2022

Copy link
Copy Markdown
Member

Benchmarks Report 🐌

Benchmarks for #3377 compared to master:

  • All benchmarks have the same speed
  • 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.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net472 811μs 434ns 1.68μs 0.403 0 0 3.22 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 558μs 338ns 1.27μs 0 0 0 2.63 KB
#3377 WriteAndFlushEnrichedTraces net472 804μs 673ns 2.61μs 0.401 0 0 3.22 KB
#3377 WriteAndFlushEnrichedTraces netcoreapp3.1 541μs 320ns 1.24μs 0 0 0 2.63 KB
Benchmarks.Trace.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net472 196ns 0.0447ns 0.161ns 0.0701 0 0 441 B
master AllCycleSimpleBody netcoreapp3.1 254ns 0.17ns 0.659ns 0.00601 0 0 440 B
master AllCycleMoreComplexBody net472 197ns 0.0723ns 0.28ns 0.0663 0 0 417 B
master AllCycleMoreComplexBody netcoreapp3.1 255ns 0.27ns 1.05ns 0.00555 0 0 416 B
master BodyExtractorSimpleBody net472 276ns 0.173ns 0.646ns 0.0574 0 0 361 B
master BodyExtractorSimpleBody netcoreapp3.1 258ns 0.175ns 0.679ns 0.00377 0 0 272 B
master BodyExtractorMoreComplexBody net472 16.1μs 7.21ns 27ns 1.2 0.0161 0 7.62 KB
master BodyExtractorMoreComplexBody netcoreapp3.1 13.3μs 5.12ns 18.5ns 0.0923 0 0 6.75 KB
#3377 AllCycleSimpleBody net472 185ns 0.0498ns 0.18ns 0.0701 9.41E-05 0 441 B
#3377 AllCycleSimpleBody netcoreapp3.1 244ns 0.109ns 0.421ns 0.00606 0 0 440 B
#3377 AllCycleMoreComplexBody net472 181ns 0.0729ns 0.273ns 0.0662 0 0 417 B
#3377 AllCycleMoreComplexBody netcoreapp3.1 238ns 0.0562ns 0.203ns 0.00567 0 0 416 B
#3377 BodyExtractorSimpleBody net472 272ns 0.135ns 0.504ns 0.0573 0 0 361 B
#3377 BodyExtractorSimpleBody netcoreapp3.1 251ns 0.115ns 0.43ns 0.00368 0 0 272 B
#3377 BodyExtractorMoreComplexBody net472 15.7μs 10.3ns 38.7ns 1.2 0.0158 0 7.62 KB
#3377 BodyExtractorMoreComplexBody netcoreapp3.1 12.8μs 6.14ns 23ns 0.0894 0 0 6.75 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
master SendRequest netcoreapp3.1 178μs 276ns 1.07μs 0.267 0 0 20.66 KB
#3377 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#3377 SendRequest netcoreapp3.1 177μs 189ns 707ns 0.267 0 0 20.66 KB
Benchmarks.Trace.DbCommandBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net472 1.81μs 1.2ns 4.64ns 0.157 0.000909 0 995 B
master ExecuteNonQuery netcoreapp3.1 1.42μs 0.463ns 1.67ns 0.0135 0 0 984 B
#3377 ExecuteNonQuery net472 1.75μs 0.736ns 2.85ns 0.158 0.000871 0 995 B
#3377 ExecuteNonQuery netcoreapp3.1 1.34μs 0.411ns 1.54ns 0.0134 0 0 984 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net472 2.57μs 0.855ns 3.2ns 0.191 0 0 1.2 KB
master CallElasticsearch netcoreapp3.1 1.54μs 0.628ns 2.27ns 0.0154 0 0 1.14 KB
master CallElasticsearchAsync net472 2.65μs 1.34ns 5.01ns 0.212 0 0 1.34 KB
master CallElasticsearchAsync netcoreapp3.1 1.63μs 0.513ns 1.92ns 0.0171 0 0 1.26 KB
#3377 CallElasticsearch net472 2.55μs 2.68ns 10ns 0.191 0 0 1.2 KB
#3377 CallElasticsearch netcoreapp3.1 1.51μs 0.3ns 1.12ns 0.0159 0 0 1.14 KB
#3377 CallElasticsearchAsync net472 2.63μs 1.92ns 7.17ns 0.212 0 0 1.34 KB
#3377 CallElasticsearchAsync netcoreapp3.1 1.62μs 0.314ns 1.13ns 0.017 0 0 1.26 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net472 2.64μs 1.84ns 7.14ns 0.233 0 0 1.47 KB
master ExecuteAsync netcoreapp3.1 1.72μs 0.709ns 2.46ns 0.0188 0 0 1.39 KB
#3377 ExecuteAsync net472 2.66μs 2.05ns 7.94ns 0.233 0 0 1.47 KB
#3377 ExecuteAsync netcoreapp3.1 1.85μs 0.614ns 2.13ns 0.0184 0 0 1.39 KB
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net472 5.95μs 2.16ns 8.09ns 0.445 0 0 2.82 KB
master SendAsync netcoreapp3.1 3.71μs 1.02ns 3.68ns 0.0353 0 0 2.65 KB
#3377 SendAsync net472 5.75μs 2.24ns 8.38ns 0.448 0 0 2.82 KB
#3377 SendAsync netcoreapp3.1 3.69μs 0.959ns 3.59ns 0.0353 0 0 2.65 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 3.19μs 4.13ns 15.4ns 0.297 0 0 1.88 KB
master EnrichedLog netcoreapp3.1 2.55μs 2.59ns 9.68ns 0.0256 0 0 1.91 KB
#3377 EnrichedLog net472 3.25μs 1.74ns 6.52ns 0.297 0 0 1.88 KB
#3377 EnrichedLog netcoreapp3.1 2.5μs 1.48ns 5.55ns 0.0261 0 0 1.91 KB
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 150μs 66.3ns 257ns 0.748 0.224 0 4.72 KB
master EnrichedLog netcoreapp3.1 118μs 68.3ns 237ns 0.0591 0 0 4.55 KB
#3377 EnrichedLog net472 152μs 130ns 502ns 0.681 0.227 0 4.72 KB
#3377 EnrichedLog netcoreapp3.1 122μs 204ns 789ns 0.0605 0 0 4.55 KB
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 5.84μs 2.37ns 9.18ns 0.579 0.00293 0 3.65 KB
master EnrichedLog netcoreapp3.1 4.4μs 1.26ns 4.55ns 0.0551 0 0 3.98 KB
#3377 EnrichedLog net472 5.72μs 3.49ns 13ns 0.58 0.00284 0 3.65 KB
#3377 EnrichedLog netcoreapp3.1 4.44μs 1.72ns 6.18ns 0.0533 0 0 3.98 KB
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net472 2.22μs 4.44ns 17.2ns 0.225 0 0 1.42 KB
master SendReceive netcoreapp3.1 1.84μs 0.609ns 2.28ns 0.0184 0 0 1.37 KB
#3377 SendReceive net472 2.26μs 2.41ns 9.33ns 0.225 0 0 1.42 KB
#3377 SendReceive netcoreapp3.1 1.71μs 1.59ns 6.14ns 0.018 0 0 1.37 KB
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 5.07μs 1.53ns 5.92ns 0.363 0 0 2.3 KB
master EnrichedLog netcoreapp3.1 4.19μs 1.54ns 5.76ns 0.0254 0 0 1.86 KB
#3377 EnrichedLog net472 5.07μs 4.83ns 18.1ns 0.363 0 0 2.3 KB
#3377 EnrichedLog netcoreapp3.1 4.03μs 1.73ns 6.69ns 0.0242 0 0 1.86 KB
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net472 1.23μs 0.308ns 1.15ns 0.136 0 0 859 B
master StartFinishSpan netcoreapp3.1 936ns 0.354ns 1.33ns 0.0112 0 0 808 B
master StartFinishScope net472 1.49μs 0.35ns 1.26ns 0.149 0 0 939 B
master StartFinishScope netcoreapp3.1 1.05μs 0.479ns 1.85ns 0.0125 0 0 928 B
#3377 StartFinishSpan net472 1.16μs 0.399ns 1.54ns 0.136 0 0 859 B
#3377 StartFinishSpan netcoreapp3.1 894ns 0.681ns 2.46ns 0.0107 0 0 808 B
#3377 StartFinishScope net472 1.47μs 0.421ns 1.63ns 0.149 0 0 939 B
#3377 StartFinishScope netcoreapp3.1 1.06μs 0.357ns 1.38ns 0.0128 0 0 928 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net472 1.57μs 0.352ns 1.32ns 0.149 0 0 939 B
master RunOnMethodBegin netcoreapp3.1 1.16μs 0.389ns 1.45ns 0.0124 0 0 928 B
#3377 RunOnMethodBegin net472 1.5μs 0.561ns 2.17ns 0.149 0 0 939 B
#3377 RunOnMethodBegin netcoreapp3.1 1.13μs 0.514ns 1.99ns 0.0124 0 0 928 B

@andrewlock

andrewlock commented Oct 21, 2022

Copy link
Copy Markdown
Member

Code Coverage Report 📊

✔️ Merging #3377 into master will not change line coverage
✔️ Merging #3377 into master will not change branch coverage
⛔ Merging #3377 into master will will increase complexity by 2

master #3377 Change
Lines 19610 / 27081 19658 / 27081
Lines % 72% 73% 0% ✔️
Branches 11602 / 16764 11632 / 16766
Branches % 69% 69% 0% ✔️
Complexity 18146 18148 2 ⛔

View the full report for further details:

Datadog.Trace Breakdown ✔️

master #3377 Change
Lines % 72% 73% 0% ✔️
Branches % 69% 69% 0% ✔️
Complexity 18146 18148 2 ⛔

The following classes have significant coverage changes.

File Line coverage change Branch coverage change Complexity change
Datadog.Trace.Ci.GitInfo 5% ✔️ 8% ✔️ 0 ✔️

View the full reports for further details:

@link04
link04 merged commit 807e090 into master Oct 21, 2022
@link04
link04 deleted the maximo/logging-span-details-first branch October 21, 2022 17:44
@github-actions github-actions Bot added this to the vNext milestone Oct 21, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@tonyredondo tonyredondo tonyredondo approved these changes
@lucaspimentel lucaspimentel lucaspimentel approved these changes
@andrewlock andrewlock andrewlock approved these changes
@pierotibou pierotibou pierotibou approved these changes

Assignees

No one assigned

Labels

area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations)

Projects

None yet

Milestone

2.18.0

Development

Successfully merging this pull request may close these issues.

5 participants

@link04 @andrewlock @tonyredondo @lucaspimentel @pierotibou