Reporting TagWith / TagWithCallsite to OpenTelemetry?

[christophwille]

Is it possible to not only add the tag as a comment to the query but actually enrich the OpenTelemetry span of the query?

        var blog = await sqlServerDb.Blogs
            .OrderBy(b => b.BlogId)
            .TagWith("Getting published blog posts")
            .FirstAsync();

https://github.com/christophwille/OTel-de-Wille/blob/087e2dbd2972b25297da008a079c27950cb324d3/aspnet-aspiredashboard/Program.cs#L171

Screenshot of the as-is situation in Aspire Dashboard (note that due to having EF / SQL wired up I do see the execution):

Maybe is there something for the wire-up?

                    .AddHttpClientInstrumentation()
                    // .AddSqlClientInstrumentation()
                    .AddEntityFrameworkCoreInstrumentation(options =>
                    {
                        //options.EnrichWithIDbCommand = (activity, command) =>
                        //{
                        //    var stateDisplayName = $"{command.CommandType} main";
                        //    activity.DisplayName = stateDisplayName;
                        //    activity.SetTag("db.name", stateDisplayName);
                        //};
                    })

https://github.com/christophwille/OTel-de-Wille/blob/087e2dbd2972b25297da008a079c27950cb324d3/aspnet-aspiredashboard/WebApplicationBuilderExtensions.cs#L62

[christophwille]

                    .AddEntityFrameworkCoreInstrumentation(options =>
                    {
                        options.EnrichWithIDbCommand = (activity, command) =>
                        {
                            // A very hacky way to transfer WithTag (one liners)
                            string cmdText = command.CommandText;
                            if (cmdText.StartsWith("-- "))
                            {
                                string tag = cmdText.Substring(3, cmdText.IndexOf('\n') - 4);
                                activity.SetTag("db.tag", tag);
                            }

                        };
                    })

This is very nasty... a better way would be nice to have.

Is this actually topic for here or https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.EntityFrameworkCore ?

Would there be a convenient interceptor "On Query executed" that would allow me to read the tags? (and send to OTel)?

[roji]

@christophwille that's an interesting idea, thanks.

First, EF itself doesn't (currently) emit OpenTelemetry diagnostics for command execution - this is why the instrumentation library exists. The logic has traditionally been that such tracing belongs at a lower layer - in the ADO.NET driver - which has access to a lot more useful information (EF is just an intermediate higher layer here, generating the SQL etc.). Npgsql emits tracing information out-of-the-box, and instrumentation exists for e.g. SqlClient to do similar things. I've opened https://github.com/dotnet/aspire/issues/2427 to track enabling the instrumentation by default for SqlClient when using Aspire.

I've also opened https://github.com/npgsql/npgsql/issues/5595 to allow setting a tag on NpgsqlCommand at the Npgsql, since this doesn't necessarily concern only EF users (direct users of Npgsql may want to do the same). If/when that's done, the EF PG provider specifically could use it to flow down the EF tag.

In any case, I don't know the instrumentation library very well, and I specifically don't know whether the query tags are accessible in the place where the trace is emitted (probably not); you may indeed want to investigate/ask in https://github.com/open-telemetry/opentelemetry-dotnet-contrib/tree/main/src/OpenTelemetry.Instrumentation.EntityFrameworkCore indeed. Otherwise, hooking up manual enrichment and parsing the SQL as you've done will indeed work; it doesn't look great, but the main problem is if EF changes its tag comment format, which isn't likely to happen. I can't reall

[christophwille]

Thanks for the explanation. Are the TagWith / TagWithCallersite "tags" accessible in eg an interceptor? Because all I need to do is

Activity.Current?.SetTag("db.Tag", theTags);

That is all there is to adding the tags to an already existing activity.

Edit: on new codebases without TagWith usage yet I could actually add a new extension method that does Otel+TagWith in one go and doesn't need other shenanigans.

[roji]

Thanks for the explanation. Are the TagWith / TagWithCallersite "tags" accessible in eg an interceptor?

Yes. In fact, one of the reasons to use a tag is to instruct an interceptor to rewrite the query in some way; see these docs for an example.

[christophwille]

By "accessible" I was more looking for e.g. a .Tags property than doing text parsing again. I'll rephrase my question: are the tags available in a typed manner in an interceptor?

[roji]

are the tags available in a typed manner in an interceptor?

No. But many people are using StartsWith successfully - I wouldn't go and build something complex just in order to avoid that.

[tcartwright]

I did something like this for AppInsights (talked about it on this SO post:

using System.Data.Common;
using System.Diagnostics;
using Microsoft.ApplicationInsights;
using Microsoft.ApplicationInsights.DataContracts;
using Microsoft.EntityFrameworkCore.Diagnostics;

namespace SvApi.AppInsights;

public class EFCommandInterceptor : DbCommandInterceptor
{
    private TelemetryClient _telemetryClient;

    public EFCommandInterceptor(TelemetryClient telemetryClient)
    {
        _telemetryClient = telemetryClient;
    }

    public override InterceptionResult<int> NonQueryExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<int> result)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return base.NonQueryExecuting(command, eventData, result);
    }
    public override async ValueTask<InterceptionResult<int>> NonQueryExecutingAsync(DbCommand command, CommandEventData eventData, InterceptionResult<int> result, CancellationToken cancellationToken = default)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return await base.NonQueryExecutingAsync(command, eventData, result, cancellationToken);
    }

    public override InterceptionResult<DbDataReader> ReaderExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<DbDataReader> result)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return base.ReaderExecuting(command, eventData, result);
    }
    public override async ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command, CommandEventData eventData, InterceptionResult<DbDataReader> result, CancellationToken cancellationToken = default)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return await base.ReaderExecutingAsync(command, eventData, result, cancellationToken);
    }

    public override InterceptionResult<object> ScalarExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<object> result)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return base.ScalarExecuting(command, eventData, result);
    }
    public override async ValueTask<InterceptionResult<object>> ScalarExecutingAsync(DbCommand command, CommandEventData eventData, InterceptionResult<object> result, CancellationToken cancellationToken = default)
    {
        var msg = InsightsTrace();
        FormatMessage(command, msg);
        return await base.ScalarExecutingAsync(command, eventData, result, cancellationToken);
    }

    protected string? InsightsTrace(bool includeLineNumber = true)
    {
        if (_telemetryClient is null)
            return null;

        // would prefer to use the new Caller attributes, but I can't figure out how to get the parameter information there
        StackTrace stack = new StackTrace(true);
        var frames = stack.GetFrames();
        var frame = frames
            .Skip(2)
            .SkipWhile(f => f.GetFileName() is null)
            .FirstOrDefault();

        if (frame is null) { return null; }
        var methodInfo = frame.GetMethod();
        var parameters = string.Join(", ", methodInfo.GetParameters().Select(p => $"{p.ParameterType.Name} {p.Name}"));
        var lineNumber = includeLineNumber ? $" Line: {frame.GetFileLineNumber()}" : "";
        var message = $"{methodInfo.ReflectedType.FullName}.{methodInfo.Name}({parameters}){lineNumber}";
        Trace.WriteLine($"{this.GetType().Assembly.GetName().Name}: {message}");
        _telemetryClient.TrackTrace(message, SeverityLevel.Information);
        return message;
    }

    private static void FormatMessage(DbCommand command, string? msg)
    {
        if (string.IsNullOrWhiteSpace(msg)) { msg = "No Line Info"; }
        command.CommandText = $"/* {msg} */\r\n{command.CommandText}";
    }
}

[roji]

Programmatically walking up the stack is both very slow and very brittle - it's generally discouraged.

[tcartwright]

@roji It actually isn't that slow, I understand there is a performance cost. Yes, it can be brittle. I go into that a bit here