Get CurrentSpan in .Net APM Agent

Elastic Observability APM
1

I was looking to add labels to the CurrentSpan in an Asp.Net Core application. The basic is idea I had was to use an EF Core Interceptor to add the labels to the CurrentSpan. However, when I access the CurrentSpan it is null. Any Suggestions on how I can access it from here? Or maybe it's just not available because it's closed already. The transaction is not null, but I would like to attach the information it to the span that it is associated with the DB query.

Thanks!

public class ApmEFInterceptor : DbCommandInterceptor
    {
        private static readonly int _dbCommandNameLength = 50;

        public override DbDataReader ReaderExecuted(DbCommand command, CommandExecutedEventData eventData, DbDataReader result)
        {
            SetSpanName(command.CommandText);
            return base.ReaderExecuted(command, eventData, result);
        }

        public override Task<DbDataReader> ReaderExecutedAsync(DbCommand command, CommandExecutedEventData eventData, DbDataReader result,
            CancellationToken cancellationToken = new CancellationToken())
        {
            SetSpanName(command.CommandText);
            return base.ReaderExecutedAsync(command, eventData, result, cancellationToken);
        }

        public override int NonQueryExecuted(DbCommand command, CommandExecutedEventData eventData, int result)
        {
            SetRowsAffected(result);
            SetSpanName(command.CommandText);
            return base.NonQueryExecuted(command, eventData, result);
        }

        public override Task<int> NonQueryExecutedAsync(DbCommand command, CommandExecutedEventData eventData, int result,
            CancellationToken cancellationToken = new CancellationToken())
        {
            SetRowsAffected(result);
            SetSpanName(command.CommandText);
            return base.NonQueryExecutedAsync(command, eventData, result, cancellationToken);
        }

        public override InterceptionResult DataReaderDisposing(DbCommand command, DataReaderDisposingEventData eventData,
            InterceptionResult result)
        {
            SetRowsRead(eventData.ReadCount);
            return base.DataReaderDisposing(command, eventData, result);
        }

        private static void SetRowsAffected(int rowsAffected)
        {
            Agent.Tracer.CurrentSpan?.Labels?.Add("rows_affected", rowsAffected.ToString());
        }

        private static void SetRowsRead(int rowsRead)
        {
            Agent.Tracer.CurrentSpan?.Labels?.Add("rows_read", rowsRead.ToString());
        }
        private static void SetSpanName(string command)
        {
            var currentSpan = Agent.Tracer.CurrentSpan;
            Console.WriteLine($"Is null {currentSpan == null}");
            if (currentSpan == null)
            {
                return;
            }

            var length = Math.Min(command?.Length ?? _dbCommandNameLength, _dbCommandNameLength);
            currentSpan.Name = command?.Substring(0, length);
        }
    }
2

Hi @rainbowkid11 - welcome back!

It's interesting - I didn't know that they added DbCommandInterceptor to EF Core as well. .NET Agent already uses DbCommandInterceptor to automatically create spans for EF6. By looking at that code you can see that what is missing in your code is starting and ending the span for the corresponding DB operation. I don't think you need to use Agent.Tracer.CurrentSpan the way you are trying to use it - you only need CurrentSpan to make the new span a child of CurrentSpan as Agent does here. In addition you need some context object to carry the new span you create in DB operation starting callback (i.e., ...Executing()) so you can call End() on that span in DB operation ended callback (i.e., ...Executed()). Agent's Ef6Interceptor uses DbCommandInterceptionContext<T>.SetUserState()/.FindUserState() for that purpose. I see that EF Core's IDbCommandInterceptor doesn't receive DbCommandInterceptionContext<T> in its callbacks - maybe CommandEventData parameter can be used to carry span between ...Executing and ...Executed callbacks.

3

Of course a better long term solution for your use case would be to implement this feature - Agent's public API should allow user to register filters similar to those of node.js agent. We welcome community contributions if you would like to take on it :slight_smile:

4

@Sergey_Kleyman Thanks for info! What I really wanted was to hook into the span created by the .Net agent for the database request so I can manipulate the name (to display on Kibana) and also add a couple of labels. A better idea as you mentioned is the filter feature. If I have time I may give it a try.

Thanks for the amazing work!

5

For now this worked! Not so elegant but it seems to work.

using System;
using System.Collections.Generic;
using System.Data.Common;
using System.Threading;
using System.Threading.Tasks;
using Elastic.Apm;
using Elastic.Apm.Api;
using Microsoft.EntityFrameworkCore.Diagnostics;

namespace Shared.Apm
{
    public class ApmEFInterceptor : DbCommandInterceptor
    {
        private static readonly int _dbCommandNameLength = 100;
        private ISpan _span;

        

        public override Task<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command, CommandEventData eventData, InterceptionResult<DbDataReader> result,
            CancellationToken cancellationToken = new CancellationToken())
        {
            SetSpan();
            return base.ReaderExecutingAsync(command, eventData, result, cancellationToken);
        }
        public override InterceptionResult<DbDataReader> ReaderExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<DbDataReader> result)
        {
            SetSpan();
            return base.ReaderExecuting(command, eventData, result);
        }

        public override InterceptionResult<int> NonQueryExecuting(DbCommand command, CommandEventData eventData, InterceptionResult<int> result)
        {
            SetSpan();
            return base.NonQueryExecuting(command, eventData, result);
        }
        public override Task<InterceptionResult<int>> NonQueryExecutingAsync(DbCommand command, CommandEventData eventData, InterceptionResult<int> result,
            CancellationToken cancellationToken = new CancellationToken())
        {
            SetSpan();
            return base.NonQueryExecutingAsync(command, eventData, result, cancellationToken);
        }


        public override int NonQueryExecuted(DbCommand command, CommandExecutedEventData eventData, int result)
        {
            SetRowsAffected(result);
            return base.NonQueryExecuted(command, eventData, result);
        }


        public override Task<int> NonQueryExecutedAsync(DbCommand command, CommandExecutedEventData eventData, int result,
            CancellationToken cancellationToken = new CancellationToken())
        {
            SetRowsAffected(result);
            return base.NonQueryExecutedAsync(command, eventData, result, cancellationToken);
        }

        public override InterceptionResult DataReaderDisposing(DbCommand command, DataReaderDisposingEventData eventData,
            InterceptionResult result)
        {
            SetRowsRead(eventData.ReadCount);
            return base.DataReaderDisposing(command, eventData, result);
        }

        private void SetRowsAffected(int rowsAffected)
        {
            _span?.Labels?.Add("rows_affected", rowsAffected.ToString());
            if (_span != null)
            {
                _span.Name = $"DML Database Call - {rowsAffected} Rows Affected";
            }
        }

        private void SetRowsRead(int rowsRead)
        {
            // database reports 1 more than actual read
            rowsRead--;
            _span?.Labels?.Add("rows_read", rowsRead.ToString());
            if (_span != null)
            {
                _span.Name = $"Select Database Call - {rowsRead} Row(s) Read";
            }
        }
        private void SetSpanName(string command)
        {
            if (_span == null)
            {
                return;
            }

            var length = Math.Min(command?.Length ?? _dbCommandNameLength, _dbCommandNameLength);
            _span.Name = command?.Substring(0, length);
        }

        private void SetSpan()
        {
            _span = Agent.Tracer.CurrentSpan;
        }
    }
}
6

I'm glad it works for you although I would be very careful because your code implicitly relies
on the order in which EF Core notifies DbCommandInterceptor-s and DiagnosticSource listeners (currently Agent uses DiagnosticSource listener to automatically create DB spans for EF Core). If any of these EF Core and .NET Agent implementation details change your code might break. What you can do to at least detect if something went wrong and that you possibly changing a wrong span is to check if Agent.Tracer.CurrentSpan?.Type is Elastic.Apm.Api.ApiConstants.TypeDb (it's a public constant for "db").

7

Yes, that seems to be the main use case for the filter feature - to manipulate event objects before they undergo final processing and are sent to APM Server.

8

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.