/// <summary>
/// Starts the correlation context.
/// </summary>
/// <param name="correlationId">The correlation id to create the context for.</param>
/// <returns>The created correlation context (also accessible via <see cref="ICorrelationContextAccessor"/>), or null if diagnostics and logging is disabled.</returns>
public CorrelationContext Start(string correlationId)
{
if (correlationId == null)
{
throw new ArgumentNullException(nameof(correlationId));
}
bool isDiagnosticsEnabled = _diagnosticListener?.IsEnabled() ?? false;
bool isLoggingEnabled = _logger.IsEnabled(LogLevel.Critical);
if (isDiagnosticsEnabled || isLoggingEnabled)
{
CorrelationContext context = _correlationContextFactory.Create(correlationId);
if (isDiagnosticsEnabled)
{
// TODO: add Activity support
//var activity = new Activity("Correlated-Request");
//activity.SetParentId(correlationId);
//_diagnosticListener.StartActivity(activity, new {})
}
if (isLoggingEnabled)
{
_logScope = _logger.BeginCorrelatedScope(correlationId);
}
_activity?.Start(context);
return(context);
}
return(null);
}
public override Task OpenAsync(CancellationToken cancellationToken)
{
Guid operationId = s_diagnosticListener.WriteConnectionOpenBefore(this);
PrepareStatisticsForNewConnection();
SqlStatistics statistics = null;
try
{
statistics = SqlStatistics.StartTimer(Statistics);
TaskCompletionSource <DbConnectionInternal> completion = new TaskCompletionSource <DbConnectionInternal>();
TaskCompletionSource <object> result = new TaskCompletionSource <object>();
if (s_diagnosticListener.IsEnabled(SqlClientDiagnosticListenerExtensions.SqlAfterOpenConnection) ||
s_diagnosticListener.IsEnabled(SqlClientDiagnosticListenerExtensions.SqlErrorOpenConnection))
{
result.Task.ContinueWith((t) =>
{
if (t.Exception != null)
{
s_diagnosticListener.WriteConnectionOpenError(operationId, this, t.Exception);
}
else
{
s_diagnosticListener.WriteConnectionOpenAfter(operationId, this);
}
}, TaskScheduler.Default);
}
if (cancellationToken.IsCancellationRequested)
{
result.SetCanceled();
return(result.Task);
}
bool completed;
try
{
completed = TryOpen(completion);
}
catch (Exception e)
{
s_diagnosticListener.WriteConnectionOpenError(operationId, this, e);
result.SetException(e);
return(result.Task);
}
if (completed)
{
result.SetResult(null);
}
else
{
CancellationTokenRegistration registration = new CancellationTokenRegistration();
if (cancellationToken.CanBeCanceled)
{
registration = cancellationToken.Register(s => ((TaskCompletionSource <DbConnectionInternal>)s).TrySetCanceled(), completion);
}
OpenAsyncRetry retry = new OpenAsyncRetry(this, completion, result, registration);
_currentCompletion = new Tuple <TaskCompletionSource <DbConnectionInternal>, Task>(completion, result.Task);
completion.Task.ContinueWith(retry.Retry, TaskScheduler.Default);
return(result.Task);
}
return(result.Task);
}
catch (Exception ex)
{
s_diagnosticListener.WriteConnectionOpenError(operationId, this, ex);
throw;
}
finally
{
SqlStatistics.StopTimer(statistics);
}
}
public void MultiSubscriber()
{
using (DiagnosticListener listener = new DiagnosticListener("TestingMultiSubscriber"))
{
DiagnosticSource source = listener;
var subscriber1Result = new List <KeyValuePair <string, object> >();
Predicate <string> subscriber1Predicate = name => (name == "DataForSubscriber1");
var subscriber1Observer = new ObserverToList <TelemData>(subscriber1Result);
var subscriber2Result = new List <KeyValuePair <string, object> >();
Predicate <string> subscriber2Predicate = name => (name == "DataForSubscriber2");
var subscriber2Observer = new ObserverToList <TelemData>(subscriber2Result);
// Get two subscribers going.
using (var subscription1 = listener.Subscribe(subscriber1Observer, subscriber1Predicate))
{
using (var subscription2 = listener.Subscribe(subscriber2Observer, subscriber2Predicate))
{
// Things that neither subscribe to get filtered out.
if (listener.IsEnabled("DataToFilterOut"))
{
listener.Write("DataToFilterOut", -1);
}
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
// If a Source does not use the IsEnabled, then every subscriber gets it.
subscriber1Result.Clear();
subscriber2Result.Clear();
listener.Write("UnfilteredData", 3);
Assert.Equal(1, subscriber1Result.Count);
Assert.Equal("UnfilteredData", subscriber1Result[0].Key);
Assert.Equal(3, (int)subscriber1Result[0].Value);
Assert.Equal(1, subscriber2Result.Count);
Assert.Equal("UnfilteredData", subscriber2Result[0].Key);
Assert.Equal(3, (int)subscriber2Result[0].Value);
/****************************************************/
// Filters not filter out everything, they are just a performance optimization.
// Here you actually get more than you want even though you use a filter
subscriber1Result.Clear();
subscriber2Result.Clear();
if (listener.IsEnabled("DataForSubscriber1"))
{
listener.Write("DataForSubscriber1", 1);
}
Assert.Equal(1, subscriber1Result.Count);
Assert.Equal("DataForSubscriber1", subscriber1Result[0].Key);
Assert.Equal(1, (int)subscriber1Result[0].Value);
// Subscriber 2 happens to get it
Assert.Equal(1, subscriber2Result.Count);
Assert.Equal("DataForSubscriber1", subscriber2Result[0].Key);
Assert.Equal(1, (int)subscriber2Result[0].Value);
/****************************************************/
subscriber1Result.Clear();
subscriber2Result.Clear();
if (listener.IsEnabled("DataForSubscriber2"))
{
listener.Write("DataForSubscriber2", 2);
}
// Subscriber 1 happens to get it
Assert.Equal(1, subscriber1Result.Count);
Assert.Equal("DataForSubscriber2", subscriber1Result[0].Key);
Assert.Equal(2, (int)subscriber1Result[0].Value);
Assert.Equal(1, subscriber2Result.Count);
Assert.Equal("DataForSubscriber2", subscriber2Result[0].Key);
Assert.Equal(2, (int)subscriber2Result[0].Value);
} // subscriber2 drops out
/*********************************************************************/
/* Only Subscriber 1 is left */
/*********************************************************************/
// Things that neither subscribe to get filtered out.
subscriber1Result.Clear();
subscriber2Result.Clear();
if (listener.IsEnabled("DataToFilterOut"))
{
listener.Write("DataToFilterOut", -1);
}
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
// If a Source does not use the IsEnabled, then every subscriber gets it.
subscriber1Result.Clear();
listener.Write("UnfilteredData", 3);
Assert.Equal(1, subscriber1Result.Count);
Assert.Equal("UnfilteredData", subscriber1Result[0].Key);
Assert.Equal(3, (int)subscriber1Result[0].Value);
// Subscriber 2 has dropped out.
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
// Filters not filter out everything, they are just a performance optimization.
// Here you actually get more than you want even though you use a filter
subscriber1Result.Clear();
if (listener.IsEnabled("DataForSubscriber1"))
{
listener.Write("DataForSubscriber1", 1);
}
Assert.Equal(1, subscriber1Result.Count);
Assert.Equal("DataForSubscriber1", subscriber1Result[0].Key);
Assert.Equal(1, (int)subscriber1Result[0].Value);
// Subscriber 2 has dropped out.
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
subscriber1Result.Clear();
if (listener.IsEnabled("DataForSubscriber2"))
{
listener.Write("DataForSubscriber2", 2);
}
// Subscriber 1 filters
Assert.Equal(0, subscriber1Result.Count);
// Subscriber 2 has dropped out
Assert.Equal(0, subscriber2Result.Count);
} // subscriber1 drops out
/*********************************************************************/
/* No Subscribers are left */
/*********************************************************************/
// Things that neither subscribe to get filtered out.
subscriber1Result.Clear();
subscriber2Result.Clear();
if (listener.IsEnabled("DataToFilterOut"))
{
listener.Write("DataToFilterOut", -1);
}
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
// If a Source does not use the IsEnabled, then every subscriber gets it.
listener.Write("UnfilteredData", 3);
// No one subscribing
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
// Filters not filter out everything, they are just a performance optimization.
// Here you actually get more than you want even though you use a filter
if (listener.IsEnabled("DataForSubscriber1"))
{
listener.Write("DataForSubscriber1", 1);
}
// No one subscribing
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
/****************************************************/
if (listener.IsEnabled("DataForSubscriber2"))
{
listener.Write("DataForSubscriber2", 2);
}
// No one subscribing
Assert.Equal(0, subscriber1Result.Count);
Assert.Equal(0, subscriber2Result.Count);
}
}
public void TestNulls()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestNullsTestSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types
eventSourceListener.Enable("TestNullsTestSource/TestEvent1:cls.Url;cls_Point_X=cls.Point.X");
/***************************************************************************************/
// Emit a null arguments object.
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", null);
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(0, eventSourceListener.LastEvent.Arguments.Count);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object with nulls in it.
MyClass val = null;
string strVal = null;
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { cls = val, propStr = "propVal1", propStrNull = strVal });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(3, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("", eventSourceListener.LastEvent.Arguments["cls"]); // Tostring() on a null end up as an empty string.
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("", eventSourceListener.LastEvent.Arguments["propStrNull"]); // null strings get turned into empty strings
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object that points at null things
MyClass val1 = new MyClass()
{
Url = "myUrlVal", Point = null
};
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { cls = val1, propStr = "propVal1" });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(3, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val1.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("myUrlVal", eventSourceListener.LastEvent.Arguments["Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object that points at null things (variation 2)
MyClass val2 = new MyClass()
{
Url = null, Point = new MyPoint()
{
X = 8, Y = 9
}
};
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { cls = val2, propStr = "propVal1" });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(3, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val2.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("8", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
eventSourceListener.ResetEventCountAndLastEvent();
}
}
public Activity BeginParsing(IQueryContext context)
{
var payload = new
{
context
};
if (_source.IsEnabled(DiagnosticNames.Parsing, payload))
{
var activity = new Activity(DiagnosticNames.Parsing);
_source.StartActivity(activity, payload);
return(activity);
}
return(null);
}
public void TestBadProperties()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestBadPropertiesSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// This has a syntax error in the Url case, so it should be ignored.
eventSourceListener.Enable("TestBadPropertiesSource/TestEvent1:cls.Ur-+l");
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass() { Url = "MyUrl", Point = new MyPoint() { X = 3, Y = 5 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestBadPropertiesSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("4", eventSourceListener.LastEvent.Arguments["propInt"]);
eventSourceListener.ResetEventCountAndLastEvent();
}
}
public void TestNulls()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestNullsTestSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types
eventSourceListener.Enable("TestNullsTestSource/TestEvent1:cls.Url;cls_Point_X=cls.Point.X");
/***************************************************************************************/
// Emit a null arguments object.
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", null);
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(0, eventSourceListener.LastEvent.Arguments.Count);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object with nulls in it.
MyClass val = null;
string strVal = null;
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { cls = val, propStr = "propVal1", propStrNull = strVal });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("", eventSourceListener.LastEvent.Arguments["propStrNull"]); // null strings get turned into empty strings
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object that points at null things
MyClass val1 = new MyClass() { Url = "myUrlVal", Point = null };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { cls = val1, propStr = "propVal1" });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("myUrlVal", eventSourceListener.LastEvent.Arguments["Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an arguments object that points at null things (variation 2)
MyClass val2 = new MyClass() { Url = null, Point = new MyPoint() { X = 8, Y = 9 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { cls = val2, propStr = "propVal1" });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNullsTestSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("propVal1", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("8", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
eventSourceListener.ResetEventCountAndLastEvent();
}
}
public void TestWildCardEventName()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestWildCardEventNameSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types
eventSourceListener.Enable("TestWildCardEventNameSource");
/***************************************************************************************/
// Emit an event, check that all implicit properties are generated
MyClass val = new MyClass() { Url = "MyUrl", Point = new MyPoint() { X = 3, Y = 5 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardEventNameSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("4", eventSourceListener.LastEvent.Arguments["propInt"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit the same event, with a different set of implicit properties
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr2 = "hi2", cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardEventNameSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(1, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hi2", eventSourceListener.LastEvent.Arguments["propStr2"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event from another diagnostic source with the same event name.
// It will be filtered out.
using (var diagnosticSourceListener2 = new DiagnosticListener("TestWildCardEventNameSource2"))
{
if (diagnosticSourceListener2.IsEnabled("TestEvent1"))
diagnosticSourceListener2.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
}
}
internal DiagnosticScope(string name, DiagnosticListener source)
{
_name = name;
_source = source;
_activity = _source.IsEnabled() ? new Activity(_name) : null;
}
private T TrackOperation <T>(
DiagnosticListener listener,
string activityName,
TaskStatus status,
string parentId = null,
Action operation = null) where T : OperationTelemetry
{
Activity activity = null;
int itemCountBefore = this.sentItems.Count;
if (listener.IsEnabled(activityName))
{
activity = new Activity(activityName);
activity.AddTag("peer.hostname", "eventhubname.servicebus.windows.net");
activity.AddTag("eh.event_hub_name", "ehname");
activity.AddTag("eh.partition_key", "SomePartitionKeyHere");
activity.AddTag("eh.client_id", "EventHubClient1(ehname)");
if (Activity.Current == null && parentId != null)
{
activity.SetParentId(parentId);
}
if (listener.IsEnabled(activityName + ".Start"))
{
listener.StartActivity(
activity,
new
{
Entity = "ehname",
Endpoint = new Uri("sb://eventhubname.servicebus.windows.net/"),
PartitionKey = "SomePartitionKeyHere"
});
}
else
{
activity.Start();
}
}
operation?.Invoke();
if (activity != null)
{
listener.StopActivity(
activity,
new
{
Entity = "ehname",
Endpoint = new Uri("sb://eventhubname.servicebus.windows.net/"),
PartitionKey = "SomePartitionKeyHere",
Status = status
});
// a single new telemetry item was added
Assert.AreEqual(itemCountBefore + 1, this.sentItems.Count);
return(this.sentItems.Last() as T);
}
// no new telemetry items were added
Assert.AreEqual(itemCountBefore, this.sentItems.Count);
return(null);
}
public EnabledDiagnosticSource?IfEnabled(string name)
{
return(_enabled && (Activity.Current != null || _source.IsEnabled(name))
? new EnabledDiagnosticSource(_source, name)
: default(EnabledDiagnosticSource?));
}
public void BeginRequest(HttpContext httpContext, HostingApplication.Context context)
{
long startTimestamp = 0;
if (HostingEventSource.Log.IsEnabled())
{
context.EventLogEnabled = true;
// To keep the hot path short we defer logging in this function to non-inlines
RecordRequestStartEventLog(httpContext);
}
var diagnosticListenerEnabled = _diagnosticListener.IsEnabled();
var diagnosticListenerActivityCreationEnabled = (diagnosticListenerEnabled && _diagnosticListener.IsEnabled(ActivityName, httpContext));
var loggingEnabled = _logger.IsEnabled(LogLevel.Critical);
if (loggingEnabled || diagnosticListenerActivityCreationEnabled || _activitySource.HasListeners())
{
context.Activity = StartActivity(httpContext, loggingEnabled, diagnosticListenerActivityCreationEnabled, out var hasDiagnosticListener);
context.HasDiagnosticListener = hasDiagnosticListener;
if (context.Activity is Activity activity)
{
if (httpContext.Features.Get <IHttpActivityFeature>() is IHttpActivityFeature feature)
{
feature.Activity = activity;
}
else
{
httpContext.Features.Set(context.HttpActivityFeature);
}
}
}
if (diagnosticListenerEnabled)
{
if (_diagnosticListener.IsEnabled(DeprecatedDiagnosticsBeginRequestKey))
{
startTimestamp = Stopwatch.GetTimestamp();
RecordBeginRequestDiagnostics(httpContext, startTimestamp);
}
}
// To avoid allocation, return a null scope if the logger is not on at least to some degree.
if (loggingEnabled)
{
// Scope may be relevant for a different level of logging, so we always create it
// see: https://github.com/aspnet/Hosting/pull/944
// Scope can be null if logging is not on.
context.Scope = Log.RequestScope(_logger, httpContext);
if (_logger.IsEnabled(LogLevel.Information))
{
if (startTimestamp == 0)
{
startTimestamp = Stopwatch.GetTimestamp();
}
// Non-inline
LogRequestStarting(context);
}
}
context.StartTimestamp = startTimestamp;
}
private async ValueTask ProcessAsync(HttpPipelineMessage message, ReadOnlyMemory <HttpPipelinePolicy> pipeline, bool isAsync)
{
if (!_isDistributedTracingEnabled)
{
if (isAsync)
{
await ProcessNextAsync(message, pipeline, true).ConfigureAwait(false);
}
else
{
ProcessNextAsync(message, pipeline, false).EnsureCompleted();
}
return;
}
if (!s_diagnosticSource.IsEnabled())
{
await ProcessNextAsync(message, pipeline, isAsync).ConfigureAwait(false);
return;
}
var activity = new Activity("Azure.Core.Http.Request");
activity.AddTag("http.method", message.Request.Method.Method);
activity.AddTag("http.url", message.Request.Uri.ToString());
activity.AddTag("requestId", message.Request.ClientRequestId);
if (message.Request.Headers.TryGetValue("User-Agent", out string?userAgent))
{
activity.AddTag("http.user_agent", userAgent);
}
var diagnosticSourceActivityEnabled = s_diagnosticSource.IsEnabled(activity.OperationName, message);
if (diagnosticSourceActivityEnabled)
{
s_diagnosticSource.StartActivity(activity, message);
}
else
{
activity.Start();
}
if (isAsync)
{
await ProcessNextAsync(message, pipeline, true).ConfigureAwait(false);
}
else
{
ProcessNextAsync(message, pipeline, false).EnsureCompleted();
}
activity.AddTag("http.status_code", message.Response.Status.ToString(CultureInfo.InvariantCulture));
activity.AddTag("serviceRequestId", message.Response.Headers.RequestId);
if (diagnosticSourceActivityEnabled)
{
s_diagnosticSource.StopActivity(activity, message);
}
else
{
activity.Stop();
}
}
public virtual ViewEngineResult FindView(ActionContext actionContext, ViewResult viewResult)
{
if (actionContext == null)
{
throw new ArgumentNullException(nameof(actionContext));
}
if (viewResult == null)
{
throw new ArgumentNullException(nameof(viewResult));
}
var viewEngine = viewResult.ViewEngine ?? ViewEngine;
var viewName = viewResult.ViewName ?? GetActionName(actionContext) ?? string.Empty;
var stopwatch = ValueStopwatch.StartNew();
var result = viewEngine.GetView(executingFilePath: null, viewPath: viewName, isMainPage: true);
var originalResult = result;
if (!result.Success)
{
result = viewEngine.FindView(actionContext, viewName, isMainPage: true);
}
Logger.ViewResultExecuting(result.ViewName);
if (!result.Success)
{
if (originalResult.SearchedLocations.Any())
{
if (result.SearchedLocations.Any())
{
// Return a new ViewEngineResult listing all searched locations.
var locations = new List <string>(originalResult.SearchedLocations);
locations.AddRange(result.SearchedLocations);
result = ViewEngineResult.NotFound(viewName, locations);
}
else
{
// GetView() searched locations but FindView() did not. Use first ViewEngineResult.
result = originalResult;
}
}
}
if (DiagnosticListener.IsEnabled())
{
OutputDiagnostics(actionContext, viewResult, viewName, result);
}
if (result.Success)
{
Logger.ViewFound(result.View, stopwatch.GetElapsedTime());
}
else
{
Logger.ViewNotFound(viewName, result.SearchedLocations);
}
return(result);
}
public void LinuxNewLineConventions()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("LinuxNewLineConventionsSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types You can have whitespace
// before and after each spec. Use \n rather than \r\n
eventSourceListener.Enable(
" LinuxNewLineConventionsSource/TestEvent1:-cls_Point_X=cls.Point.X\n" +
" LinuxNewLineConventionsSource/TestEvent2:-cls_Url=cls.Url\n"
);
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass() { Url = "MyUrl", Point = new MyPoint() { X = 3, Y = 5 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("LinuxNewLineConventionsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(1, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("3", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event that matches the second pattern.
if (diagnosticSourceListener.IsEnabled("TestEvent2"))
diagnosticSourceListener.Write("TestEvent2", new { prop2Str = "hello", prop2Int = 8, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("LinuxNewLineConventionsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(1, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("MyUrl", eventSourceListener.LastEvent.Arguments["cls_Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
// Emit an event that does not match either pattern. (thus will be filtered out)
if (diagnosticSourceListener.IsEnabled("TestEvent3"))
diagnosticSourceListener.Write("TestEvent3", new { propStr = "prop3", });
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
}
// Make sure that there are no Diagnostic Listeners left over.
DiagnosticListener.AllListeners.Subscribe(DiagnosticSourceTest.MakeObserver(delegate (DiagnosticListener listen)
{
Assert.True(!listen.Name.StartsWith("BuildTestSource"));
}));
}
public void TestWildCardSourceName()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener1 = new DiagnosticListener("TestWildCardSourceName1"))
using (var diagnosticSourceListener2 = new DiagnosticListener("TestWildCardSourceName2"))
{
eventSourceListener.Filter = (DiagnosticSourceEvent evnt) => evnt.SourceName.StartsWith("TestWildCardSourceName");
// Turn On Everything. Note that because of concurrent testing, we may get other sources as well.
// but we filter them out because we set eventSourceListener.Filter.
eventSourceListener.Enable("");
Assert.True(diagnosticSourceListener1.IsEnabled("TestEvent1"));
Assert.True(diagnosticSourceListener1.IsEnabled("TestEvent2"));
Assert.True(diagnosticSourceListener2.IsEnabled("TestEvent1"));
Assert.True(diagnosticSourceListener2.IsEnabled("TestEvent2"));
Assert.Equal(0, eventSourceListener.EventCount);
diagnosticSourceListener1.Write("TestEvent1", new { prop111 = "prop111Val", prop112 = 112 });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardSourceName1", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("prop111Val", eventSourceListener.LastEvent.Arguments["prop111"]);
Assert.Equal("112", eventSourceListener.LastEvent.Arguments["prop112"]);
eventSourceListener.ResetEventCountAndLastEvent();
diagnosticSourceListener1.Write("TestEvent2", new { prop121 = "prop121Val", prop122 = 122 });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardSourceName1", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("prop121Val", eventSourceListener.LastEvent.Arguments["prop121"]);
Assert.Equal("122", eventSourceListener.LastEvent.Arguments["prop122"]);
eventSourceListener.ResetEventCountAndLastEvent();
diagnosticSourceListener2.Write("TestEvent1", new { prop211 = "prop211Val", prop212 = 212 });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardSourceName2", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("prop211Val", eventSourceListener.LastEvent.Arguments["prop211"]);
Assert.Equal("212", eventSourceListener.LastEvent.Arguments["prop212"]);
eventSourceListener.ResetEventCountAndLastEvent();
diagnosticSourceListener2.Write("TestEvent2", new { prop221 = "prop221Val", prop222 = 122 });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardSourceName2", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("prop221Val", eventSourceListener.LastEvent.Arguments["prop221"]);
Assert.Equal("122", eventSourceListener.LastEvent.Arguments["prop222"]);
eventSourceListener.ResetEventCountAndLastEvent();
}
}
private async ValueTask <HttpResponseMessage> SendAsyncCore(HttpRequestMessage request, bool async,
CancellationToken cancellationToken)
{
// HttpClientHandler is responsible to call static DiagnosticsHandler.IsEnabled() before forwarding request here.
// It will check if propagation is on (because parent Activity exists or there is a listener) or off (forcibly disabled)
// This code won't be called unless consumer unsubscribes from DiagnosticListener right after the check.
// So some requests happening right after subscription starts might not be instrumented. Similarly,
// when consumer unsubscribes, extra requests might be instrumented
if (request == null)
{
throw new ArgumentNullException(nameof(request), SR.net_http_handler_norequest);
}
Activity? activity = null;
DiagnosticListener diagnosticListener = Settings.s_diagnosticListener;
// if there is no listener, but propagation is enabled (with previous IsEnabled() check)
// do not write any events just start/stop Activity and propagate Ids
if (!diagnosticListener.IsEnabled())
{
activity = new Activity(DiagnosticsHandlerLoggingStrings.ActivityName);
activity.Start();
InjectHeaders(activity, request);
try
{
return(async ?
await base.SendAsync(request, cancellationToken).ConfigureAwait(false) :
base.Send(request, cancellationToken));
}
finally
{
activity.Stop();
}
}
Guid loggingRequestId = Guid.Empty;
// There is a listener. Check if listener wants to be notified about HttpClient Activities
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityName, request))
{
activity = new Activity(DiagnosticsHandlerLoggingStrings.ActivityName);
// Only send start event to users who subscribed for it, but start activity anyway
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ActivityStartName))
{
diagnosticListener.StartActivity(activity, new ActivityStartData(request));
}
else
{
activity.Start();
}
}
// try to write System.Net.Http.Request event (deprecated)
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.RequestWriteNameDeprecated))
{
long timestamp = Stopwatch.GetTimestamp();
loggingRequestId = Guid.NewGuid();
diagnosticListener.Write(DiagnosticsHandlerLoggingStrings.RequestWriteNameDeprecated,
new RequestData(request, loggingRequestId, timestamp));
}
// If we are on at all, we propagate current activity information
Activity?currentActivity = Activity.Current;
if (currentActivity != null)
{
InjectHeaders(currentActivity, request);
}
HttpResponseMessage?response = null;
TaskStatus taskStatus = TaskStatus.RanToCompletion;
try
{
response = async ?
await base.SendAsync(request, cancellationToken).ConfigureAwait(false) :
base.Send(request, cancellationToken);
return(response);
}
catch (OperationCanceledException)
{
taskStatus = TaskStatus.Canceled;
// we'll report task status in HttpRequestOut.Stop
throw;
}
catch (Exception ex)
{
taskStatus = TaskStatus.Faulted;
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ExceptionEventName))
{
// If request was initially instrumented, Activity.Current has all necessary context for logging
// Request is passed to provide some context if instrumentation was disabled and to avoid
// extensive Activity.Tags usage to tunnel request properties
diagnosticListener.Write(DiagnosticsHandlerLoggingStrings.ExceptionEventName, new ExceptionData(ex, request));
}
throw;
}
finally
{
// always stop activity if it was started
if (activity != null)
{
diagnosticListener.StopActivity(activity, new ActivityStopData(
response,
// If request is failed or cancelled, there is no response, therefore no information about request;
// pass the request in the payload, so consumers can have it in Stop for failed/canceled requests
// and not retain all requests in Start
request,
taskStatus));
}
// Try to write System.Net.Http.Response event (deprecated)
if (diagnosticListener.IsEnabled(DiagnosticsHandlerLoggingStrings.ResponseWriteNameDeprecated))
{
long timestamp = Stopwatch.GetTimestamp();
diagnosticListener.Write(DiagnosticsHandlerLoggingStrings.ResponseWriteNameDeprecated,
new ResponseData(
response,
loggingRequestId,
timestamp,
taskStatus));
}
}
}
public void TestSpecificEvents()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestSpecificEventsSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types You can have whitespace
// before and after each spec.
eventSourceListener.Enable(
" TestSpecificEventsSource/TestEvent1:cls_Point_X=cls.Point.X;cls_Point_Y=cls.Point.Y\r\n" +
" TestSpecificEventsSource/TestEvent2:cls_Url=cls.Url\r\n"
);
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass() { Url = "MyUrl", Point = new MyPoint() { X = 3, Y = 5 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestSpecificEventsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(4, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("4", eventSourceListener.LastEvent.Arguments["propInt"]);
Assert.Equal("3", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
Assert.Equal("5", eventSourceListener.LastEvent.Arguments["cls_Point_Y"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event that matches the second pattern.
if (diagnosticSourceListener.IsEnabled("TestEvent2"))
diagnosticSourceListener.Write("TestEvent2", new { prop2Str = "hello", prop2Int = 8, cls = val });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestSpecificEventsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(3, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hello", eventSourceListener.LastEvent.Arguments["prop2Str"]);
Assert.Equal("8", eventSourceListener.LastEvent.Arguments["prop2Int"]);
Assert.Equal("MyUrl", eventSourceListener.LastEvent.Arguments["cls_Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
// Emit an event that does not match either pattern. (thus will be filtered out)
if (diagnosticSourceListener.IsEnabled("TestEvent3"))
diagnosticSourceListener.Write("TestEvent3", new { propStr = "prop3", });
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
/***************************************************************************************/
// Emit an event from another diagnostic source with the same event name.
// It will be filtered out.
using (var diagnosticSourceListener2 = new DiagnosticListener("TestSpecificEventsSource2"))
{
if (diagnosticSourceListener2.IsEnabled("TestEvent1"))
diagnosticSourceListener2.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
// Disable all the listener and insure that no more events come through.
eventSourceListener.Disable();
diagnosticSourceListener.Write("TestEvent1", null);
diagnosticSourceListener.Write("TestEvent2", null);
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be received.
}
// Make sure that there are no Diagnostic Listeners left over.
DiagnosticListener.AllListeners.Subscribe(DiagnosticSourceTest.MakeObserver(delegate (DiagnosticListener listen)
{
Assert.True(!listen.Name.StartsWith("BuildTestSource"));
}));
}
public void LinuxNewLineConventions()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("LinuxNewLineConventionsSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types You can have whitespace
// before and after each spec. Use \n rather than \r\n
eventSourceListener.Enable(
" LinuxNewLineConventionsSource/TestEvent1:-cls_Point_X=cls.Point.X\n" +
" LinuxNewLineConventionsSource/TestEvent2:-cls_Url=cls.Url\n"
);
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass()
{
Url = "MyUrl", Point = new MyPoint()
{
X = 3, Y = 5
}
};
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("LinuxNewLineConventionsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(1, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("3", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event that matches the second pattern.
if (diagnosticSourceListener.IsEnabled("TestEvent2"))
{
diagnosticSourceListener.Write("TestEvent2", new { prop2Str = "hello", prop2Int = 8, cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("LinuxNewLineConventionsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(1, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("MyUrl", eventSourceListener.LastEvent.Arguments["cls_Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
// Emit an event that does not match either pattern. (thus will be filtered out)
if (diagnosticSourceListener.IsEnabled("TestEvent3"))
{
diagnosticSourceListener.Write("TestEvent3", new { propStr = "prop3", });
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
}
// Make sure that there are no Diagnostic Listeners left over.
DiagnosticListener.AllListeners.Subscribe(DiagnosticSourceTest.MakeObserver(delegate(DiagnosticListener listen)
{
Assert.True(!listen.Name.StartsWith("BuildTestSource"));
}));
}
public void TestNoImplicitTransforms()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestNoImplicitTransformsSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// use the - prefix to suppress the implicit properties. Thus you should only get propStr and Url.
eventSourceListener.Enable("TestNoImplicitTransformsSource/TestEvent1:-propStr;cls.Url");
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass() { Url = "MyUrl", Point = new MyPoint() { X = 3, Y = 5 } };
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val, propStr2 = "there" });
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestNoImplicitTransformsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("MyUrl", eventSourceListener.LastEvent.Arguments["Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
}
}
public void TestWildCardEventName()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestWildCardEventNameSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types
eventSourceListener.Enable("TestWildCardEventNameSource");
/***************************************************************************************/
// Emit an event, check that all implicit properties are generated
MyClass val = new MyClass()
{
Url = "MyUrl", Point = new MyPoint()
{
X = 3, Y = 5
}
};
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardEventNameSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(3, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("4", eventSourceListener.LastEvent.Arguments["propInt"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit the same event, with a different set of implicit properties
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { propStr2 = "hi2", cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestWildCardEventNameSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(2, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("hi2", eventSourceListener.LastEvent.Arguments["propStr2"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event from another diagnostic source with the same event name.
// It will be filtered out.
using (var diagnosticSourceListener2 = new DiagnosticListener("TestWildCardEventNameSource2"))
{
if (diagnosticSourceListener2.IsEnabled("TestEvent1"))
{
diagnosticSourceListener2.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
}
}
public void TestSpecificEvents()
{
using (var eventSourceListener = new TestDiagnosticSourceEventListener())
using (var diagnosticSourceListener = new DiagnosticListener("TestSpecificEventsSource"))
{
Assert.Equal(0, eventSourceListener.EventCount);
// Turn on events with both implicit and explicit types You can have whitespace
// before and after each spec.
eventSourceListener.Enable(
" TestSpecificEventsSource/TestEvent1:cls_Point_X=cls.Point.X;cls_Point_Y=cls.Point.Y\r\n" +
" TestSpecificEventsSource/TestEvent2:cls_Url=cls.Url\r\n"
);
/***************************************************************************************/
// Emit an event that matches the first pattern.
MyClass val = new MyClass()
{
Url = "MyUrl", Point = new MyPoint()
{
X = 3, Y = 5
}
};
if (diagnosticSourceListener.IsEnabled("TestEvent1"))
{
diagnosticSourceListener.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestSpecificEventsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent1", eventSourceListener.LastEvent.EventName);
Assert.Equal(5, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("hi", eventSourceListener.LastEvent.Arguments["propStr"]);
Assert.Equal("4", eventSourceListener.LastEvent.Arguments["propInt"]);
Assert.Equal("3", eventSourceListener.LastEvent.Arguments["cls_Point_X"]);
Assert.Equal("5", eventSourceListener.LastEvent.Arguments["cls_Point_Y"]);
eventSourceListener.ResetEventCountAndLastEvent();
/***************************************************************************************/
// Emit an event that matches the second pattern.
if (diagnosticSourceListener.IsEnabled("TestEvent2"))
{
diagnosticSourceListener.Write("TestEvent2", new { prop2Str = "hello", prop2Int = 8, cls = val });
}
Assert.Equal(1, eventSourceListener.EventCount); // Exactly one more event has been emitted.
Assert.Equal("TestSpecificEventsSource", eventSourceListener.LastEvent.SourceName);
Assert.Equal("TestEvent2", eventSourceListener.LastEvent.EventName);
Assert.Equal(4, eventSourceListener.LastEvent.Arguments.Count);
Assert.Equal(val.GetType().FullName, eventSourceListener.LastEvent.Arguments["cls"]); // ToString on cls is the class name
Assert.Equal("hello", eventSourceListener.LastEvent.Arguments["prop2Str"]);
Assert.Equal("8", eventSourceListener.LastEvent.Arguments["prop2Int"]);
Assert.Equal("MyUrl", eventSourceListener.LastEvent.Arguments["cls_Url"]);
eventSourceListener.ResetEventCountAndLastEvent();
// Emit an event that does not match either pattern. (thus will be filtered out)
if (diagnosticSourceListener.IsEnabled("TestEvent3"))
{
diagnosticSourceListener.Write("TestEvent3", new { propStr = "prop3", });
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
/***************************************************************************************/
// Emit an event from another diagnostic source with the same event name.
// It will be filtered out.
using (var diagnosticSourceListener2 = new DiagnosticListener("TestSpecificEventsSource2"))
{
if (diagnosticSourceListener2.IsEnabled("TestEvent1"))
{
diagnosticSourceListener2.Write("TestEvent1", new { propStr = "hi", propInt = 4, cls = val });
}
}
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be fired.
// Disable all the listener and insure that no more events come through.
eventSourceListener.Disable();
diagnosticSourceListener.Write("TestEvent1", null);
diagnosticSourceListener.Write("TestEvent2", null);
Assert.Equal(0, eventSourceListener.EventCount); // No Event should be received.
}
// Make sure that there are no Diagnostic Listeners left over.
DiagnosticListener.AllListeners.Subscribe(DiagnosticSourceTest.MakeObserver(delegate(DiagnosticListener listen)
{
Assert.True(!listen.Name.StartsWith("BuildTestSource"));
}));
}
public static void DiagnosticSourceTest()
{
#region DiagnosticSource
var diagnosticListener =
new DiagnosticListener(DiagnosticStrings.DiagnosticListenerName);
////订阅方法一
//DiagnosticListener.AllListeners.Subscribe(new MyObserver<DiagnosticListener>(listener =>
//{
// //判断发布者的名字
// if (listener.Name == DiagnosticStrings.DiagnosticListenerName)
// {
// //获取订阅信息
// listener.Subscribe(new MyObserver<KeyValuePair<string, object>>(listenerData =>
// {
// Console.WriteLine($"监听名称:{listenerData.Key}");
// dynamic data = listenerData.Value;
// Console.WriteLine(data.Sql);
// }));
// }
//}));
////订阅方法二
DiagnosticListener.AllListeners.Subscribe(new MyObserver <DiagnosticListener>(listener =>
{
if (listener.Name == DiagnosticStrings.DiagnosticListenerName)
{
//适配订阅
listener.SubscribeWithAdapter(new MyDiagnosticListener());
}
}));
//订阅方法三
//diagnosticListener.SubscribeWithAdapter(new MyDiagnosticListener());
diagnosticListener.SubscribeWithAdapter(new SqlBuilderDiagnosticListener(null));
//发送日志诊断消息
if (diagnosticListener.IsEnabled(DiagnosticStrings.BeforeExecute) &&
diagnosticListener.IsEnabled(DiagnosticStrings.AfterExecute) &&
diagnosticListener.IsEnabled(DiagnosticStrings.ErrorExecute))
{
var message = new DiagnosticsMessage
{
Sql = "select * from table",
Parameters = new Dictionary <string, object>
{
["key"] = "123"
},
Timestamp = DateTimeOffset.UtcNow.ToUnixTimeMilliseconds()
};
diagnosticListener.Write(
DiagnosticStrings.BeforeExecute,
message);
message.ElapsedMilliseconds = DateTimeOffset.UtcNow.ToUnixTimeMilliseconds() - message.Timestamp;
diagnosticListener.Write(
DiagnosticStrings.AfterExecute,
message);
message.ElapsedMilliseconds = DateTimeOffset.UtcNow.ToUnixTimeMilliseconds() - message.Timestamp;
message.Exception = new Exception("测试异常");
diagnosticListener.Write(
DiagnosticStrings.ErrorExecute,
message);
}
#endregion
}