Skip to content

Commit

Permalink
[BREAKING CHANGE] DefaultTracing: Removes DefaultTraceListener to dis…
Browse files Browse the repository at this point in the history
…able tracing by default (#2926)

This PR is removing the DefaultTraceListener from the TraceSource by default unless there is a debugger attached. It is enabled by default for debugging scenario because performance is not an issue in those scenarios, and it can be helpful to root cause the issue being debugged.

The DefaultTraceListener adds a significant amount of overhead and will cause lock contention. There have been several live site incidents caused by this. This issue is more problematic for .NET Core because the app config file is not supported which make it difficult to disable it. For example, the performance project had to use reflection to get the trace source to remove it programmatically.
  • Loading branch information
j82w authored Dec 10, 2021
1 parent 4abf290 commit 15ac56e
Show file tree
Hide file tree
Showing 4 changed files with 116 additions and 15 deletions.
37 changes: 36 additions & 1 deletion Microsoft.Azure.Cosmos/src/CosmosClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ namespace Microsoft.Azure.Cosmos
{
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Net;
using System.Text;
using System.Threading;
Expand Down Expand Up @@ -119,6 +120,15 @@ static CosmosClient()
// NOTE: Native ServiceInteropWrapper.AssembliesExist has appsettings dependency which are proofed for CTL (native dll entry) scenarios.
// Revert of this depends on handling such in direct assembly
ServiceInteropWrapper.AssembliesExist = new Lazy<bool>(() => true);

Microsoft.Azure.Cosmos.Core.Trace.DefaultTrace.InitEventListener();

// If a debugger is not attached remove the DefaultTraceListener.
// DefaultTraceListener can cause lock contention leading to availability issues
if (!Debugger.IsAttached)
{
CosmosClient.RemoveDefaultTraceListener();
}
}

/// <summary>
Expand Down Expand Up @@ -257,7 +267,7 @@ internal CosmosClient(
this.ClientContext = ClientContextCore.Create(
this,
clientOptions);

this.ClientConfigurationTraceDatum = new ClientConfigurationTraceDatum(this.ClientContext, DateTime.UtcNow);
}

Expand Down Expand Up @@ -1033,6 +1043,31 @@ public virtual Task<ResponseMessage> CreateDatabaseStreamAsync(
});
}

/// <summary>
/// Removes the DefaultTraceListener which causes locking issues which leads to avability problems.
/// </summary>
private static void RemoveDefaultTraceListener()
{
if (Core.Trace.DefaultTrace.TraceSource.Listeners.Count > 0)
{
List<DefaultTraceListener> removeDefaultTraceListeners = new List<DefaultTraceListener>();
foreach (object traceListnerObject in Core.Trace.DefaultTrace.TraceSource.Listeners)
{
// The TraceSource already has the default trace listener
if (traceListnerObject is DefaultTraceListener defaultTraceListener)
{
removeDefaultTraceListeners.Add(defaultTraceListener);
}
}

// Remove all the default trace listeners
foreach (DefaultTraceListener defaultTraceListener in removeDefaultTraceListeners)
{
Core.Trace.DefaultTrace.TraceSource.Listeners.Remove(defaultTraceListener);
}
}
}

internal virtual async Task<ConsistencyLevel> GetAccountConsistencyLevelAsync()
{
if (!this.accountConsistencyLevel.HasValue)
Expand Down
2 changes: 0 additions & 2 deletions Microsoft.Azure.Cosmos/src/DocumentClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -646,8 +646,6 @@ internal virtual void Initialize(Uri serviceEndpoint,
throw new ArgumentNullException("serviceEndpoint");
}

DefaultTrace.InitEventListener();

this.queryPartitionProvider = new AsyncLazy<QueryPartitionProvider>(async () =>
{
await this.EnsureValidClientAsync(NoOpTrace.Singleton);
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,56 @@
//------------------------------------------------------------
// Copyright (c) Microsoft Corporation. All rights reserved.
//------------------------------------------------------------
namespace Microsoft.Azure.Cosmos.Tests
{
using System;
using System.Diagnostics;
using System.Net.Http;
using System.Reflection;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Azure.Cosmos.Core.Trace;
using Microsoft.VisualStudio.TestTools.UnitTesting;
using Moq;

[TestClass]
public class DefaultTracingTests
{
[TestMethod]
public void DefaultTracingEnableTest()
{
// Access cosmos client to cause the static consturctor to get called
Assert.IsTrue(CosmosClient.numberOfClientsCreated >= 0);

if (!Debugger.IsAttached)
{
Assert.IsFalse(this.DefaultTraceHasDefaultTraceListener());
DefaultTrace.TraceSource.Listeners.Add(new DefaultTraceListener());
}

Assert.IsTrue(this.DefaultTraceHasDefaultTraceListener());
typeof(CosmosClient).GetMethod("RemoveDefaultTraceListener", BindingFlags.Static | BindingFlags.NonPublic).Invoke(null, null);
//CosmosClient.RemoveDefaultTraceListener();
Assert.IsFalse(this.DefaultTraceHasDefaultTraceListener());
}

private bool DefaultTraceHasDefaultTraceListener()
{
if (DefaultTrace.TraceSource.Listeners.Count == 0)
{
return false;
}

foreach (TraceListener listener in DefaultTrace.TraceSource.Listeners)
{
if (listener is DefaultTraceListener)
{
return true;
}
}

DefaultTrace.TraceSource.Listeners.Clear();
return false;
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -60,7 +60,7 @@ void TraceHandler(string message)
{
Assert.IsFalse(failedToResolve, "Failure to resolve should happen only once.");
failedToResolve = true;
didNotRetryMessage = message.Substring(failedToResolveMessage.Length).Split('\n')[0];
didNotRetryMessage = message[failedToResolveMessage.Length..].Split('\n')[0];
}

if (failedToResolve && message.Contains("NOT be retried") && message.Contains(didNotRetryMessage))
Expand All @@ -71,24 +71,36 @@ void TraceHandler(string message)
Console.WriteLine(message);
}

DefaultTrace.TraceSource.Listeners.Add(new TestTraceListener { Callback = TraceHandler });
TestTraceListener testTraceListener = new TestTraceListener { Callback = TraceHandler };
DefaultTrace.TraceSource.Listeners.Add(testTraceListener);
DefaultTrace.InitEventListener();

try
{
DocumentClient myclient = new DocumentClient(new Uri(accountEndpoint), "base64encodedurl",
new ConnectionPolicy
{
});
try
{
DocumentClient myclient = new DocumentClient(new Uri(accountEndpoint), "base64encodedurl",
new ConnectionPolicy
{
});

await myclient.OpenAsync();
await myclient.OpenAsync();
}
catch
{
}

DefaultTrace.TraceSource.Flush();

// it should fail fast and not into the retry logic.
Assert.IsTrue(failedToResolve, "OpenAsync did not fail to resolve. No matching trace was received.");
Assert.IsTrue(didNotRetry, "OpenAsync did not fail without retrying. No matching trace was received.");
}
catch
finally
{

DefaultTrace.TraceSource.Listeners.Remove(testTraceListener);
}

// it should fail fast and not into the retry logic.
Assert.IsTrue(failedToResolve, "OpenAsync did not fail to resolve. No matching trace was received.");
Assert.IsTrue(didNotRetry, "OpenAsync did not fail without retrying. No matching trace was received.");
}

/// <summary>
Expand Down

0 comments on commit 15ac56e

Please sign in to comment.