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

Fix race condition in RequestTelemetryLogger #59669

Merged
merged 1 commit into from
Feb 22, 2022
Merged
Changes from all commits
Commits
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 @@ -4,8 +4,6 @@

using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Diagnostics.CodeAnalysis;
using System.Threading;
using Microsoft.CodeAnalysis.Internal.Log;

Expand All @@ -17,7 +15,7 @@ internal partial class RequestExecutionQueue
/// Logs metadata on LSP requests (duration, success / failure metrics)
/// for this particular LSP server instance.
/// </summary>
internal class RequestTelemetryLogger : IDisposable
internal sealed class RequestTelemetryLogger : IDisposable
{
private const string QueuedDurationKey = "QueuedDuration";

Expand All @@ -26,7 +24,7 @@ internal class RequestTelemetryLogger : IDisposable
/// <summary>
/// Histogram to aggregate the time in queue metrics.
/// </summary>
private HistogramLogAggregator? _queuedDurationLogAggregator;
private readonly HistogramLogAggregator _queuedDurationLogAggregator;

/// <summary>
/// Histogram to aggregate total request duration metrics.
Expand All @@ -36,7 +34,7 @@ internal class RequestTelemetryLogger : IDisposable
/// This provides highly detailed buckets when duration is in MS, but less detailed
/// when the duration is in terms of seconds or minutes.
/// </summary>
private HistogramLogAggregator? _requestDurationLogAggregator;
private readonly HistogramLogAggregator _requestDurationLogAggregator;

/// <summary>
/// Store request counters in a concurrent dictionary as non-mutating LSP requests can
Expand All @@ -46,6 +44,8 @@ internal class RequestTelemetryLogger : IDisposable

private readonly LogAggregator _findDocumentResults;

private int _disposed;

public RequestTelemetryLogger(string serverTypeName)
{
_serverTypeName = serverTypeName;
Expand Down Expand Up @@ -79,10 +79,10 @@ public void UpdateTelemetryData(
{
// Find the bucket corresponding to the queued duration and update the count of durations in that bucket.
// This is not broken down per method as time in queue is not specific to an LSP method.
_queuedDurationLogAggregator?.IncreaseCount(QueuedDurationKey, Convert.ToDecimal(queuedDuration.TotalMilliseconds));
_queuedDurationLogAggregator.IncreaseCount(QueuedDurationKey, Convert.ToDecimal(queuedDuration.TotalMilliseconds));

// Store the request time metrics per LSP method.
_requestDurationLogAggregator?.IncreaseCount(methodName, Convert.ToDecimal(ComputeLogValue(requestDuration.TotalMilliseconds)));
_requestDurationLogAggregator.IncreaseCount(methodName, Convert.ToDecimal(ComputeLogValue(requestDuration.TotalMilliseconds)));
_requestCounters.GetOrAdd(methodName, (_) => new Counter()).IncrementCount(result);
}

Expand All @@ -103,8 +103,12 @@ private static double ComputeLogValue(double durationInMS)
/// </summary>
public void Dispose()
{
if (_queuedDurationLogAggregator is null || _queuedDurationLogAggregator.IsEmpty
|| _requestDurationLogAggregator is null || _requestDurationLogAggregator.IsEmpty)
if (Interlocked.Exchange(ref _disposed, 1) != 0)
{
return;
}

if (_queuedDurationLogAggregator.IsEmpty || _requestDurationLogAggregator.IsEmpty)
{
return;
}
Expand Down Expand Up @@ -150,10 +154,7 @@ public void Dispose()
}
}));

// Clear telemetry we've published in case dispose is called multiple times.
_requestCounters.Clear();
_queuedDurationLogAggregator = null;
_requestDurationLogAggregator = null;
}

private class Counter
Expand Down