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.

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

DSM Full propagation mode for SQL Server #5859

Merged
merged 25 commits into from
Sep 5, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
25 commits
Select commit Hold shift + click to select a range
8c00441
inject trace context via set context
vandonr Jul 24, 2024
b18a8ac
little bit of refactoring
vandonr Jul 25, 2024
80af8b5
copy the tags when reusing them
vandonr Jul 26, 2024
7c1ef10
wider system tests
vandonr Jul 26, 2024
f8cb802
generate xml and fix type of variable
vandonr Aug 14, 2024
08ece1e
rewrite context bytes generation to return byte array
vandonr Aug 20, 2024
87a2142
rewrite again but with proper endianess
vandonr Aug 20, 2024
094dfed
fix expected tags for integration tests
vandonr Aug 21, 2024
c87e6d2
update snapshots
vandonr Aug 21, 2024
b292664
fix comment in test
vandonr Aug 21, 2024
e5c6d9c
bigger trace and span ID in test
vandonr Aug 21, 2024
419a54f
use generic operation name in tests where it doesn't matter
vandonr Aug 21, 2024
111e373
change of plans: no span on the instrumentation
vandonr Aug 29, 2024
c7fe369
Merge remote-tracking branch 'origin/master' into vandonr/setcontext
vandonr Aug 29, 2024
50aafe2
save time spent on integration in span
vandonr Aug 30, 2024
afe8145
longer variable name
vandonr Aug 30, 2024
2eecd39
undo changes to samples that were not meant to be commited
vandonr Aug 30, 2024
03bef4f
don't include instrumentation time in the query span
vandonr Sep 2, 2024
98e3690
const
vandonr Sep 4, 2024
af3efd8
avoid nullcheck
vandonr Sep 4, 2024
3645905
imports cleanup
vandonr Sep 4, 2024
9c0d70e
set sampling prio from trace context in tests
vandonr Sep 4, 2024
bc85d08
reduce new object creation
vandonr Sep 4, 2024
77d32dc
Merge branch 'master' into vandonr/setcontext
vandonr Sep 4, 2024
d7429c6
test for both tracer versions
vandonr Sep 5, 2024
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -202,9 +202,13 @@
<type fullname="System.Data.CommandType" />
<type fullname="System.Data.Common.DbCommand" />
<type fullname="System.Data.Common.DbConnectionStringBuilder" />
<type fullname="System.Data.DbType" />
<type fullname="System.Data.IDataParameter" />
<type fullname="System.Data.IDataParameterCollection" />
<type fullname="System.Data.IDataRecord" />
<type fullname="System.Data.IDbCommand" />
<type fullname="System.Data.IDbConnection" />
<type fullname="System.Data.IDbDataParameter" />
</assembly>
<assembly fullname="System.Data.SqlClient" />
<assembly fullname="System.Data.SQLite" />
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,14 +8,11 @@
using System;
using System.Collections.Generic;
using System.Data;
using System.Data.SqlTypes;
using System.Diagnostics.CodeAnalysis;
using System.Threading;
using Datadog.Trace.AppSec;
using Datadog.Trace.AppSec.Rasp;
using Datadog.Trace.Configuration;
using Datadog.Trace.DatabaseMonitoring;
using Datadog.Trace.Iast;
using Datadog.Trace.Logging;
using Datadog.Trace.Tagging;
using Datadog.Trace.Util;
Expand Down Expand Up @@ -45,7 +42,7 @@ internal static class DbScopeFactory

if (parent is { Type: SpanTypes.Sql } &&
HasDbType(parent, dbType) &&
(parent.ResourceName == commandText || commandText.StartsWith(DatabaseMonitoringPropagator.DbmPrefix)))
(parent.ResourceName == commandText || commandText.StartsWith(DatabaseMonitoringPropagator.DbmPrefix) || commandText == DatabaseMonitoringPropagator.SetContextCommand))
{
// we are already instrumenting this,
// don't instrument nested methods that belong to the same stacktrace
Expand Down Expand Up @@ -103,11 +100,12 @@ internal static class DbScopeFactory
}
else
{
var propagatedCommand = DatabaseMonitoringPropagator.PropagateSpanData(tracer.Settings.DbmPropagationMode, tracer.DefaultServiceName, tagsFromConnectionString.DbName, tagsFromConnectionString.OutHost, scope.Span, integrationId, out var traceParentInjected);
var traceParentInjectedInContext = DatabaseMonitoringPropagator.PropagateDataViaContext(tracer.Settings.DbmPropagationMode, integrationId, command.Connection, scope.Span);
var propagatedCommand = DatabaseMonitoringPropagator.PropagateDataViaComment(tracer.Settings.DbmPropagationMode, tracer.DefaultServiceName, tagsFromConnectionString.DbName, tagsFromConnectionString.OutHost, scope.Span, integrationId, out var traceParentInjectedInComment);
if (!string.IsNullOrEmpty(propagatedCommand))
{
command.CommandText = $"{propagatedCommand} {commandText}";
if (traceParentInjected)
if (traceParentInjectedInComment || traceParentInjectedInContext)
{
tags.DbmTraceInjected = "true";
}
Expand All @@ -120,6 +118,10 @@ internal static class DbScopeFactory
Log.Error(ex, "Error propagating span data for DBM");
}

// we have to start the span before doing the DBM propagation work (to have the span ID)
// but ultimately, we don't want to measure the time spent instrumenting.
scope.Span.ResetStartTime();

return scope;

static bool HasDbType(Span span, string dbType)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,14 @@
// </copyright>

using System;
using System.Data;
using Datadog.Trace.Configuration;
using Datadog.Trace.Logging;
using Datadog.Trace.Propagators;
using Datadog.Trace.Tagging;
using Datadog.Trace.Util;
using Datadog.Trace.VendoredMicrosoftCode.System.Buffers.Binary;
using Datadog.Trace.Vendors.Serilog.Events;

#nullable enable

Expand All @@ -22,8 +26,12 @@ internal static class DatabaseMonitoringPropagator
private const string SqlCommentVersion = "ddpv";
private const string SqlCommentEnv = "dde";
internal const string DbmPrefix = $"/*{SqlCommentSpanService}='";
private const string ContextInfoParameterName = "@dd_trace_context";
internal const string SetContextCommand = $"set context_info {ContextInfoParameterName}";

internal static string PropagateSpanData(DbmPropagationLevel propagationStyle, string configuredServiceName, string? dbName, string? outhost, Span span, IntegrationId integrationId, out bool traceParentInjected)
private static readonly IDatadogLogger Log = DatadogLogging.GetLoggerFor(typeof(DatabaseMonitoringPropagator));

internal static string PropagateDataViaComment(DbmPropagationLevel propagationStyle, string configuredServiceName, string? dbName, string? outhost, Span span, IntegrationId integrationId, out bool traceParentInjected)
{
traceParentInjected = false;

Expand Down Expand Up @@ -73,5 +81,68 @@ internal static string PropagateSpanData(DbmPropagationLevel propagationStyle, s

return string.Empty;
}

/// <summary>
/// Uses a sql instruction to set a context for the current connection, bearing the span ID and trace ID.
/// This is meant to circumvent cache invalidation issues that occur when those values are injected in comment.
/// Currently only working for MSSQL (uses an instruction that is specific to it)
/// </summary>
/// <returns>True if the traceparent information was set</returns>
internal static bool PropagateDataViaContext(DbmPropagationLevel propagationLevel, IntegrationId integrationId, IDbConnection? connection, Span span)
{
if (propagationLevel != DbmPropagationLevel.Full || integrationId != IntegrationId.SqlClient || connection == null)
{
return false;
}

var stopwatch = System.Diagnostics.Stopwatch.StartNew();

const byte version = 0; // version can have a maximum value of 15 in the current format
var sampled = SamplingPriorityValues.IsKeep(span.Context.TraceContext.GetOrMakeSamplingDecision());
var contextValue = BuildContextValue(version, sampled, span.SpanId, span.TraceId128);

using (var injectionCommand = connection.CreateCommand())
{
injectionCommand.CommandText = SetContextCommand;

var parameter = injectionCommand.CreateParameter();
parameter.ParameterName = ContextInfoParameterName;
parameter.Value = contextValue;
parameter.DbType = DbType.Binary;
injectionCommand.Parameters.Add(parameter);

injectionCommand.ExecuteNonQuery();

if (Log.IsEnabled(LogEventLevel.Debug))
{
// avoid building the string representation in the general case where debug is disabled
Log.Debug("Span data for DBM propagated for {Integration} via context_info with value {ContextValue} (propagation level: {PropagationLevel}", integrationId, HexConverter.ToString(contextValue), propagationLevel);
lucaspimentel marked this conversation as resolved.
Show resolved Hide resolved
}
}

// Since sending the query to the DB can be a bit long, we register the time it took for transparency.
// Not using _dd because we want the customers to be able to see that tag.
span.SetMetric("dd.instrumentation.time_ms", stopwatch.Elapsed.TotalMilliseconds);
Copy link
Contributor

Choose a reason for hiding this comment

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

Is dd.instrumentation.time_ms just a one-off name or is this something common? never seen it before and search doesn't show any other usages anywhere in the org

Copy link
Contributor Author

Choose a reason for hiding this comment

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

hmm yeah it's a one off, I'm actually not aware of any existing instrumentation that would be long enough that we'd want to document how long it takes.


return true;
}

/// <summary>
/// Writes the given info in a byte array with the following format:
/// 4 bits: protocol version, 3 bits: reserved, 1 bit: sampling decision, 64 bits: spanID, 128 bits: traceID
/// </summary>
private static byte[] BuildContextValue(byte version, bool isSampled, ulong spanId, TraceId traceId)
{
var sampled = isSampled ? 1 : 0;
var versionAndSampling = (byte)(((version << 4) & 0b1111_0000) | (sampled & 0b0000_0001));
var contextBytes = new byte[1 + sizeof(ulong) + TraceId.Size];

var span = new VendoredMicrosoftCode.System.Span<byte>(contextBytes) { [0] = versionAndSampling };
BinaryPrimitives.WriteUInt64BigEndian(span.Slice(1), spanId);
BinaryPrimitives.WriteUInt64BigEndian(span.Slice(1 + sizeof(ulong)), traceId.Upper);
BinaryPrimitives.WriteUInt64BigEndian(span.Slice(1 + sizeof(ulong) + sizeof(ulong)), traceId.Lower);

return contextBytes;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -26,15 +26,17 @@ public MicrosoftDataSqlClientTests(ITestOutputHelper output)
public static IEnumerable<object[]> GetEnabledConfig()
=> from packageVersionArray in PackageVersions.MicrosoftDataSqlClient
from metadataSchemaVersion in new[] { "v0", "v1" }
select new[] { packageVersionArray[0], metadataSchemaVersion };
from dbmEnabled in new[] { true, false }
from propagation in new[] { "disabled", "service", "full" }
select new[] { packageVersionArray[0], metadataSchemaVersion, dbmEnabled, propagation };

public override Result ValidateIntegrationSpan(MockSpan span, string metadataSchemaVersion) => span.IsSqlClient(metadataSchemaVersion);

[SkippableTheory]
[MemberData(nameof(GetEnabledConfig))]
[Trait("Category", "EndToEnd")]
[Trait("RunOnWindows", "True")]
public async Task SubmitsTraces(string packageVersion, string metadataSchemaVersion)
public async Task SubmitsTraces(string packageVersion, string metadataSchemaVersion, bool dbmEnabled, string propagation)
{
// ALWAYS: 133 spans
// - SqlCommand: 21 spans (3 groups * 7 spans)
Expand Down Expand Up @@ -68,15 +70,18 @@ public async Task SubmitsTraces(string packageVersion, string metadataSchemaVers
const string dbType = "sql-server";
const string expectedOperationName = dbType + ".query";

SetEnvironmentVariable(ConfigurationKeys.DataStreamsMonitoring.Enabled, dbmEnabled ? "1" : "0");
SetEnvironmentVariable("DD_DBM_PROPAGATION_MODE", propagation);
SetEnvironmentVariable("DD_TRACE_SPAN_ATTRIBUTE_SCHEMA", metadataSchemaVersion);
var isExternalSpan = metadataSchemaVersion == "v0";
var clientSpanServiceName = isExternalSpan ? $"{EnvironmentHelper.FullSampleName}-{dbType}" : EnvironmentHelper.FullSampleName;

using var telemetry = this.ConfigureTelemetry();
using var agent = EnvironmentHelper.GetMockAgent();
using var process = await RunSampleAndWaitForExit(agent, packageVersion: packageVersion);

var spans = agent.WaitForSpans(expectedSpanCount, operationName: expectedOperationName);
int actualSpanCount = spans.Count(s => s.ParentId.HasValue); // Remove unexpected DB spans from the calculation
var actualSpanCount = spans.Count(s => s.ParentId.HasValue); // Remove unexpected DB spans from the calculation

Assert.Equal(expectedSpanCount, actualSpanCount);
ValidateIntegrationSpans(spans, metadataSchemaVersion, expectedServiceName: clientSpanServiceName, isExternalSpan);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -89,6 +89,7 @@ public async Task SubmitsTraces(string packageVersion, string metadataSchemaVers
settings.AddSimpleScrubber("peer.service: localhost", "peer.service: sqlserver");
settings.AddSimpleScrubber("peer.service: (localdb)\\MSSQLLocalDB", "peer.service: sqlserver");
settings.AddSimpleScrubber("peer.service: sqledge_arm64", "peer.service: sqlserver");
settings.AddRegexScrubber(new Regex("dd.instrumentation.time_ms: \\d+.\\d+"), "dd.instrumentation.time_ms: 123.456");
vandonr marked this conversation as resolved.
Show resolved Hide resolved

var fileName = nameof(SystemDataSqlClientTests);

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -646,6 +646,8 @@ public static Result IsSqlClientV0(this MockSpan span) => Result.FromSpan(span)
.IsOptional("db.name")
.IsPresent("out.host")
.IsOptional("_dd.base_service")
.IsOptional("_dd.dbm_trace_injected")
.IsOptional("dd.instrumentation.time_ms")
.Matches("db.type", "sql-server")
.Matches("component", "SqlClient")
.Matches("span.kind", "client"));
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -888,6 +888,8 @@ public static Result IsSqlClientV1(this MockSpan span) => Result.FromSpan(span)
.IsOptional("peer.service.remapped_from")
.IsOptional("_dd.base_service")
.MatchesOneOf("_dd.peer.service.source", "db.name", "out.host", "peer.service")
.IsOptional("_dd.dbm_trace_injected")
.IsOptional("dd.instrumentation.time_ms")
.Matches("component", "SqlClient")
.Matches("span.kind", "client"));

Expand Down
Loading
Loading