Apm-agent-dotnet: "Memory leak" in SqlEventListener

[nilsgstrabo]

We're experiencing memory growth issues when using the SqlClientDiagnosticSubscriber.
Took a dump of the running process and analyzed it in dotMemory.
Turns out a lot memory is allocated by _processingSpans.

When looking at the code I see that "ended" spans are never removed from the dictionary.
Perhaps there is a good reason to leave the span in the dictionary after it has ended. I don't know.
But if there isn't, and the span should be removed from the dictionary, then a quick fix would be to replace
if (!_processingSpans.TryGetValue(id, out var item))
with
if (!_processingSpans.TryRemove(id, out var item))

private void ProcessEndExecute(IReadOnlyList<object> payload)
{
    if (payload.Count != 3)
    {
        _logger?.Debug()
            ?.Log("EndExecute event has {PayloadCount} payload items instead of 3. Event processing is skipped.", payload.Count);
        return;
    }

    var id = Convert.ToInt32(payload[0]);
    var compositeState = Convert.ToInt32(payload[1]);
    var sqlExceptionNumber = Convert.ToInt32(payload[2]);
    var stop = Stopwatch.GetTimestamp();

    _logger?.Trace()
        ?.Log("Process EndExecute event. Id: {Id}. Composite state: {CompositeState}. Sql exception number: {SqlExceptionNumber}.", id,
            compositeState, sqlExceptionNumber);

    if (!_processingSpans.TryGetValue(id, out var item))
    {
        _logger?.Warning()
            ?.Log("Failed capturing sql statement (failed to remove from ProcessingSpans).");
        return;
    }

    var isSuccess = (compositeState & 1) == 1;
    var isSqlException = (compositeState & 2) == 2;
    // 4 - is synchronous

    item.Span.Duration = ((stop - item.Start) / (double)Stopwatch.Frequency) * 1000;

    if (isSqlException)
    {
        item.Span.CaptureError("Exception has occurred", sqlExceptionNumber != 0 ? $"SQL Exception {sqlExceptionNumber}" : null,
            null);
    }

    item.Span.End();
}

[gregkalapos]

Thanks for the analysis @nilsgstrabo!

When looking at the code I see that "ended" spans are never removed from the dictionary.

Great catch - yeah I also think that's the issue.

Perhaps there is a good reason to leave the span in the dictionary

I don't think there is a good reason - I also think that's the bug.

So, overall I agree with your analysis and suggestion.

I opened #851 which fixes this. Will push a patch for this very soon.

[gregkalapos]

Patch release solving this is out.

I close this now.

@nilsgstrabo it'd be nice if you could verify that the issue is indeed fixed in your environment - you can just leave a comment here.

If it's not fixed feel free to reopen.

[nilsgstrabo]

Thank you @gregkalapos! I will test tomorrow and let you know.
Really appreciate your quick response!

[nilsgstrabo]

Can confirm that 1.5.1 fixes the memory issue @gregkalapos
Tested 1.5.0 and 1.5.1 with the same requests, and as you can see the spans are successfully removed from the dictionary (as expected).

With version 1.5.0

With version 1.5.1

[gregkalapos]

Thanks for confirming @nilsgstrabo.