public void OnHttpRequestInStartInitializeTelemetryIfActivityParentIdIsNotNull()
{
var context = CreateContext(HttpRequestScheme, HttpRequestHost, "/Test", method: "POST");
var activity = new Activity("operation");
activity.SetParentId(Guid.NewGuid().ToString());
activity.AddBaggage("item1", "value1");
activity.AddBaggage("item2", "value2");
activity.Start();
using (var hostingListener = CreateHostingListener(true))
{
HandleRequestBegin(hostingListener, context, 0, true);
HandleRequestEnd(hostingListener, context, 0, true);
}
Assert.Single(sentTelemetry);
var requestTelemetry = this.sentTelemetry.First() as RequestTelemetry;
Assert.Equal(requestTelemetry.Id, activity.Id);
Assert.Equal(requestTelemetry.Context.Operation.Id, activity.RootId);
Assert.Equal(requestTelemetry.Context.Operation.ParentId, activity.ParentId);
Assert.Equal(requestTelemetry.Properties.Count, activity.Baggage.Count());
foreach (var prop in activity.Baggage)
{
Assert.True(requestTelemetry.Properties.ContainsKey(prop.Key));
Assert.Equal(requestTelemetry.Properties[prop.Key], prop.Value);
}
}
public async Task Send(ConsumeContext context, IPipe <ConsumeContext> next)
{
var operationName = $"Consuming message: {context.DestinationAddress.GetExchangeName()}";
using (var activity = new Activity(operationName))
{
var parentId = context.Headers.Get <string>("MT-Activity-Id");
if (parentId != null)
{
activity.SetParentId(parentId);
}
activity.Start();
activity.AddBaggage("destination-address", context.DestinationAddress?.ToString());
activity.AddBaggage("source-address", context.SourceAddress?.ToString());
activity.AddBaggage("initiator-id", context.InitiatorId?.ToString());
try
{
await next.Send(context).ConfigureAwait(false);
}
finally
{
activity.Stop();
}
}
}
public async Task GetActivityAsync_WithParentActivityAndBaggage_ReturnsActivityIncludingParentTraceId()
{
// Arrange
var grainId = Guid.NewGuid();
var baggageValue = Guid.NewGuid().ToString();
var tenantValue = Guid.NewGuid().ToString();
var activity = new Activity("test");
activity.AddBaggage("BaggageTest", baggageValue);
activity.AddBaggage("TenantId", tenantValue);
activity.Start();
var grain = _fixture.ClusterClient.GetGrain <IActivityTestGrain>(grainId);
// Act
var activityResponse = await grain.GetActivityAsync();
// Assert
Assert.NotNull(activityResponse);
Assert.NotNull(activityResponse.TraceId);
Assert.Equal(activity.Id, activityResponse.ParentId);
Assert.Equal(activity.RootId, activityResponse.RootId);
Assert.Equal(baggageValue, activityResponse.Baggage);
Assert.Equal(tenantValue, activityResponse.TenantId);
}
public async Task GetStreamActivityAsync_WithPublishGrainMessageAndBaggage_ReturnsExpectedActivityInformation()
{
var grainId = Guid.NewGuid();
var baggageValue = Guid.NewGuid().ToString();
var tenantValue = Guid.NewGuid().ToString();
var activity = new Activity("test");
activity.AddBaggage("BaggageTest", baggageValue);
activity.AddBaggage("TenantId", tenantValue);
activity.Start();
var streamProvider = _fixture.ClusterClient.GetStreamProvider(Constants.StreamProviderName);
var streamFactory = (IStreamFactory)_fixture.ClientServiceProvider.GetService(typeof(IStreamFactory));
var stream = streamFactory.GetStream <MockMessage>(streamProvider, grainId, Constants.ActivityStreamNamespace);
await stream.PublishAsync(new MockMessage());
var grain = _fixture.ClusterClient.GetGrain <IActivityTestGrain>(grainId);
var activityResponse = await grain.GetStreamActivityAsync();
// Assert
Assert.NotNull(activityResponse);
Assert.NotNull(activityResponse.TraceId);
Assert.NotNull(activityResponse.ParentId);
Assert.Equal(activity.RootId, activityResponse.RootId);
Assert.Equal(baggageValue, activityResponse.Baggage);
Assert.Equal(tenantValue, activityResponse.TenantId);
}
public void OnResponseWithParentActivity()
{
var parentActivity = new Activity("incoming_request");
parentActivity.AddBaggage("k1", "v1");
parentActivity.AddBaggage("k2", "v2");
parentActivity.Start();
parentActivity.TraceStateString = "state=some";
Guid loggingRequestId = Guid.NewGuid();
HttpRequestMessage requestMsg = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
using (var listener = new HttpCoreDiagnosticSourceListener(
this.configuration,
setComponentCorrelationHttpHeaders: true,
correlationDomainExclusionList: new string[] { "excluded.host.com" },
injectLegacyHeaders: false,
injectRequestIdInW3CMode: true,
HttpInstrumentationVersion.V1))
{
listener.OnRequest(requestMsg, loggingRequestId);
Assert.IsNotNull(Activity.Current);
var requestId = requestMsg.Headers.GetValues(RequestResponseHeaders.RequestIdHeader).Single();
var traceparent = requestMsg.Headers.GetValues("traceparent").Single();
var tracestate = requestMsg.Headers.GetValues("tracestate").Single();
Assert.AreEqual($"|{Activity.Current.TraceId.ToHexString()}.{Activity.Current.SpanId.ToHexString()}.",
requestId);
Assert.AreEqual(Activity.Current.Id, traceparent);
Assert.AreEqual("state=some", tracestate);
var correlationContextHeader =
requestMsg.Headers.GetValues(RequestResponseHeaders.CorrelationContextHeader).ToArray();
Assert.AreEqual(2, correlationContextHeader.Length);
Assert.IsTrue(correlationContextHeader.Contains("k1=v1"));
Assert.IsTrue(correlationContextHeader.Contains("k2=v2"));
Assert.IsTrue(listener.PendingDependencyTelemetry.TryGetValue(requestMsg, out var dependency));
DependencyTelemetry telemetry = dependency.Telemetry;
HttpResponseMessage responseMsg = new HttpResponseMessage(HttpStatusCode.OK)
{
RequestMessage = requestMsg
};
listener.OnResponse(responseMsg, loggingRequestId);
Assert.AreEqual(parentActivity, Activity.Current);
Assert.AreEqual(requestId, telemetry.Id);
Assert.AreEqual(parentActivity.RootId, telemetry.Context.Operation.Id);
Assert.AreEqual($"|{parentActivity.TraceId.ToHexString()}.{parentActivity.SpanId.ToHexString()}.", telemetry.Context.Operation.ParentId);
Assert.AreEqual("state=some", telemetry.Properties["tracestate"]);
// Check the operation details
this.operationDetailsInitializer.ValidateOperationDetailsCore(telemetry);
}
parentActivity.Stop();
}
public void TestActivityTrackingOptions_ShouldAddBaggageItemsAsNewScope_WhenBaggageOptionIsSet()
{
var loggerProvider = new ExternalScopeLoggerProvider();
var loggerFactory = LoggerFactory.Create(builder =>
{
builder
.Configure(o => o.ActivityTrackingOptions = ActivityTrackingOptions.Baggage)
.AddProvider(loggerProvider);
});
var logger = loggerFactory.CreateLogger("Logger");
Activity activity = new Activity("ScopeActivity");
activity.AddBaggage("testKey1", null);
activity.AddBaggage("testKey2", string.Empty);
activity.AddBaggage("testKey3", "testValue");
activity.Start();
logger.LogInformation("Message1");
activity.Stop();
foreach (string s in loggerProvider.LogText)
{
System.Console.WriteLine(s);
}
Assert.Equal("Message1", loggerProvider.LogText[0]);
Assert.Equal("testKey3:testValue, testKey2:, testKey1:", loggerProvider.LogText[2]);
}
private static void StartActivity()
{
Activity.DefaultIdFormat = ActivityIdFormat.W3C;
_activity = new Activity("Main");
_activity.AddBaggage("MyItem1", "someValue1");
_activity.AddBaggage("MyItem2", "someValue2");
_activity.Start();
}
public void AddBaggage(string key, string value)
{
if (string.IsNullOrWhiteSpace(value))
{
return;
}
Activity.AddBaggage(key, value);
Scope?.Add(key, value);
}
public void BeginWebTrackingWithParentActivityReturnsOperationItemWithTelemetryItemW3COff()
{
Activity.DefaultIdFormat = ActivityIdFormat.Hierarchical;
Activity.ForceDefaultIdFormat = true;
var parentActivity = new Activity("test");
parentActivity.SetParentId("|guid.1234_");
parentActivity.AddBaggage("k", "v");
parentActivity.Start();
var telemetry = ClientServerDependencyTracker.BeginTracking(this.telemetryClient);
Assert.AreEqual(parentActivity.Id, telemetry.Context.Operation.ParentId);
Assert.AreEqual(parentActivity.RootId, telemetry.Context.Operation.Id);
Assert.IsTrue(telemetry.Id.StartsWith(parentActivity.Id, StringComparison.Ordinal));
Assert.AreNotEqual(parentActivity.Id, telemetry.Id);
var properties = telemetry.Properties;
Assert.AreEqual(1, properties.Count);
Assert.AreEqual("v", properties["k"]);
parentActivity.Stop();
}
public void ActivitiesAreRecorded()
{
var healthReporter = Mock.Of <IHealthReporter>();
var observer = new Mock <IObserver <EventData> >();
using (var input = new DiagnosticSourceInput(new[] { new DiagnosticSourceConfiguration {
ProviderName = "test"
} }, healthReporter))
{
input.Subscribe(observer.Object);
var activityArgs = new { one = "two" };
var activity = new Activity("activity-name");
activity.AddBaggage("baggage-name", "baggage-value");
activity.AddTag("tag-name", "tag-value");
TestLog.StartActivity(activity, activityArgs);
TestLog.StopActivity(activity, activityArgs);
observer.Verify(o => o.OnNext(It.Is <EventData>(data =>
data.Payload["EventName"].Equals("activity-name.Start") &&
data.Payload["Value"].Equals(activityArgs) &&
data.Payload["baggage-name"].Equals("baggage-value") &&
data.Payload["tag-name"].Equals("tag-value")
)), Times.Once);
observer.Verify(o => o.OnNext(It.Is <EventData>(data =>
data.Payload["EventName"].Equals("activity-name.Stop") &&
data.Payload["Value"].Equals(activityArgs) &&
data.Payload["baggage-name"].Equals("baggage-value") &&
data.Payload["tag-name"].Equals("tag-value") &&
(TimeSpan)data.Payload["Duration"] != TimeSpan.Zero
)), Times.Once);
}
}
public void OnActivityStopTracksTelemetry()
{
var activity = new Activity("System.Net.Http.HttpRequestOut");
activity.AddBaggage("k", "v");
var startTime = DateTime.UtcNow.AddSeconds(-1);
activity.SetStartTime(startTime);
activity.Start();
HttpRequestMessage request = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
this.listener.OnActivityStart(request);
HttpResponseMessage response = new HttpResponseMessage(HttpStatusCode.OK);
activity.SetEndTime(startTime.AddSeconds(1));
this.listener.OnActivityStop(response, request, TaskStatus.RanToCompletion);
var telemetry = sentTelemetry.Single() as DependencyTelemetry;
Assert.AreEqual("POST /", telemetry.Name);
Assert.AreEqual(RequestUrl, telemetry.Target);
Assert.AreEqual(RemoteDependencyConstants.HTTP, telemetry.Type);
Assert.AreEqual(RequestUrlWithScheme, telemetry.Data);
Assert.AreEqual("200", telemetry.ResultCode);
Assert.AreEqual(true, telemetry.Success);
Assert.AreEqual(1, telemetry.Duration.TotalSeconds);
Assert.AreEqual(activity.RootId, telemetry.Context.Operation.Id);
Assert.AreEqual(activity.ParentId, telemetry.Context.Operation.ParentId);
Assert.AreEqual(activity.Id, telemetry.Id);
Assert.AreEqual("v", telemetry.Context.Properties["k"]);
}
private static void ReadCorrelationContext(IHeaderDictionary requestHeaders, Activity activity)
{
try
{
if (!activity.Baggage.Any())
{
string[] baggage = requestHeaders.GetCommaSeparatedValues(RequestResponseHeaders.CorrelationContextHeader);
if (baggage != StringValues.Empty)
{
foreach (var item in baggage)
{
var parts = item.Split('=');
if (parts.Length == 2)
{
var itemName = StringUtilities.EnforceMaxLength(parts[0], InjectionGuardConstants.ContextHeaderKeyMaxLength);
var itemValue = StringUtilities.EnforceMaxLength(parts[1], InjectionGuardConstants.ContextHeaderValueMaxLength);
activity.AddBaggage(itemName.Trim(), itemValue.Trim());
}
}
AspNetCoreEventSource.Instance.HostingListenerVerbose("Correlation-Context retrived from header and stored into activity baggage.");
}
}
}
catch (Exception ex)
{
AspNetCoreEventSource.Instance.HostingListenerWarning("CorrelationContext read failed.", ex.ToInvariantString());
}
}
/// <summary>
/// Creates <see cref="Activity"/> based on the tracing context stored in the <see cref="Message"/>
/// <param name="activityName">Optional Activity name</param>
/// <returns>New <see cref="Activity"/> with tracing context</returns>
/// </summary>
/// <remarks>
/// Tracing context is used to correlate telemetry between producer and consumer and
/// represented by 'Diagnostic-Id' and 'Correlation-Context' properties in <see cref="Message.UserProperties"/>.
///
/// .NET SDK automatically injects context when sending message to the ServiceBus (if diagnostics is enabled by tracing system).
///
/// <para>
/// 'Diagnostic-Id' uniquely identifies operation that enqueued message
/// </para>
/// <para>
/// 'Correlation-Context' is comma separated list of sting key value pairs represeting optional context for the operation.
/// </para>
///
/// If there is no tracing context in the message, this method returns <see cref="Activity"/> without parent.
///
/// Returned <see cref="Activity"/> needs to be started before it can be used (see example below)
/// </remarks>
/// <example>
/// <code>
/// async Task ProcessAsync()
/// {
/// var message = await messageReceiver.ReceiveAsync();
/// var activity = message.ExtractActivity();
/// activity.Start();
/// Logger.LogInformation($"Message received, Id = {Activity.Current.Id}")
/// try
/// {
/// // process message
/// }
/// catch (Exception ex)
/// {
/// Logger.LogError($"Exception {ex}, Id = {Activity.Current.Id}")
/// }
/// finally
/// {
/// activity.Stop();
/// // Activity is stopped, we no longer have it in Activity.Current, let's user activity now
/// Logger.LogInformation($"Message processed, Id = {activity.Id}, Duration = {activity.Duration}")
/// }
/// }
/// </code>
///
/// Note that every log is stamped with <see cref="Activity.Current"/>.Id, that could be used within
/// any nested method call (sync or async) - <see cref="Activity.Current"/> is an ambient context that flows with async method calls.
///
/// </example>
public static Activity ExtractActivity(this Message message, string activityName = null)
{
if (message == null)
{
throw new ArgumentNullException(nameof(message));
}
if (activityName == null)
{
activityName = ServiceBusDiagnosticSource.ProcessActivityName;
}
var activity = new Activity(activityName);
if (TryExtractId(message, out string id))
{
activity.SetParentId(id);
if (message.TryExtractContext(out IList <KeyValuePair <string, string> > ctx))
{
foreach (var kvp in ctx)
{
activity.AddBaggage(kvp.Key, kvp.Value);
}
}
}
return(activity);
}
internal static void ExtractW3CContext(HttpRequest request, Activity activity)
{
var traceParent = request.UnvalidatedGetHeader(W3CConstants.TraceParentHeader);
if (traceParent != null)
{
var traceParentStr = StringUtilities.EnforceMaxLength(traceParent, InjectionGuardConstants.TraceParentHeaderMaxLength);
activity.SetTraceparent(traceParentStr);
if (activity.ParentId == null)
{
activity.SetParentId(activity.GetTraceId());
}
}
else
{
activity.GenerateW3CContext();
}
if (!activity.Baggage.Any())
{
var baggage = request.Headers.GetNameValueCollectionFromHeader(RequestResponseHeaders.CorrelationContextHeader);
if (baggage != null && baggage.Any())
{
foreach (var item in baggage)
{
var itemName = StringUtilities.EnforceMaxLength(item.Key, InjectionGuardConstants.ContextHeaderKeyMaxLength);
var itemValue = StringUtilities.EnforceMaxLength(item.Value, InjectionGuardConstants.ContextHeaderValueMaxLength);
activity.AddBaggage(itemName, itemValue);
}
}
}
}
public void NetCore30_OnActivityStartInjectsLegacyHeaders()
{
var listenerWithLegacyHeaders = new HttpCoreDiagnosticSourceListener(
this.configuration,
setComponentCorrelationHttpHeaders: true,
correlationDomainExclusionList: new[] { "excluded.host.com" },
injectLegacyHeaders: true,
injectRequestIdInW3CMode: true,
HttpInstrumentationVersion.V3);
using (listenerWithLegacyHeaders)
{
var activity = new Activity("System.Net.Http.HttpRequestOut");
activity.AddBaggage("k", "v");
activity.TraceStateString = "trace=state";
activity.Start();
HttpRequestMessage requestMsg = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
listenerWithLegacyHeaders.OnActivityStart(requestMsg);
// Traceparent and tracestate and Correlation-Context are injected by HttpClient
// check only legacy headers here
Assert.AreEqual(activity.RootId,
requestMsg.Headers.GetValues(RequestResponseHeaders.StandardRootIdHeader).Single());
Assert.AreEqual(activity.SpanId.ToHexString(), requestMsg.Headers.GetValues(RequestResponseHeaders.StandardParentIdHeader).Single());
Assert.AreEqual(this.testApplicationId1, GetRequestContextKeyValue(requestMsg, RequestResponseHeaders.RequestContextCorrelationSourceKey));
}
}
public void BeginWebTrackingWithParentActivityReturnsOperationItemWithTelemetryItem()
{
var parentActivity = new Activity("test");
parentActivity.AddBaggage("k", "v");
parentActivity.TraceStateString = "state=some";
parentActivity.Start();
var telemetry = ClientServerDependencyTracker.BeginTracking(this.telemetryClient);
var currentActivity = Activity.Current;
Assert.IsNotNull(Activity.Current);
Assert.AreNotEqual(parentActivity, currentActivity);
Assert.AreEqual(parentActivity, currentActivity.Parent);
Assert.AreEqual(currentActivity.SpanId.ToHexString(), telemetry.Id);
Assert.AreEqual(currentActivity.TraceId.ToHexString(), telemetry.Context.Operation.Id);
Assert.AreEqual(currentActivity.ParentSpanId.ToHexString(), telemetry.Context.Operation.ParentId);
var properties = telemetry.Properties;
Assert.AreEqual(2, properties.Count);
Assert.AreEqual("v", properties["k"]);
Assert.AreEqual("state=some", properties["tracestate"]);
parentActivity.Stop();
}
private static Activity RestoreActivity(Activity root)
{
Debug.Assert(root != null);
// workaround to restore the root activity, because we don't
// have a way to change the Activity.Current
var childActivity = new Activity(root.OperationName);
childActivity.SetParentId(root.Id);
childActivity.SetStartTime(root.StartTimeUtc);
foreach (var item in root.Baggage)
{
childActivity.AddBaggage(item.Key, item.Value);
}
foreach (var item in root.Tags)
{
childActivity.AddTag(item.Key, item.Value);
}
childActivity.Start();
AspNetTelemetryCorrelationEventSource.Log.ActivityRestored(childActivity.Id);
return(childActivity);
}
public void OnActivityStartInjectsHeaders()
{
var activity = new Activity("System.Net.Http.HttpRequestOut");
activity.AddBaggage("k", "v");
activity.TraceStateString = "trace=state";
activity.Start();
HttpRequestMessage requestMsg = new HttpRequestMessage(HttpMethod.Post, RequestUrlWithScheme);
using (var listener = this.CreateHttpListener(HttpInstrumentationVersion.V2))
{
listener.OnActivityStart(requestMsg);
// Request-Id and Correlation-Context are injected by HttpClient when W3C is off,
// check W3C and legacy headers here
var requestIds = requestMsg.Headers.GetValues(RequestResponseHeaders.RequestIdHeader).ToArray();
Assert.AreEqual(1, requestIds.Length);
Assert.AreEqual($"|{activity.TraceId.ToHexString()}.{activity.SpanId.ToHexString()}.", requestIds[0]);
var traceparents = requestMsg.Headers.GetValues(W3C.W3CConstants.TraceParentHeader).ToArray();
Assert.AreEqual(1, traceparents.Length);
Assert.AreEqual(activity.Id, traceparents[0]);
var tracestates = requestMsg.Headers.GetValues(W3C.W3CConstants.TraceStateHeader).ToArray();
Assert.AreEqual(1, tracestates.Length);
Assert.AreEqual("trace=state", tracestates[0]);
Assert.IsFalse(requestMsg.Headers.Contains(RequestResponseHeaders.StandardRootIdHeader));
Assert.IsFalse(requestMsg.Headers.Contains(RequestResponseHeaders.StandardParentIdHeader));
Assert.AreEqual(this.testApplicationId1,
GetRequestContextKeyValue(requestMsg, RequestResponseHeaders.RequestContextCorrelationSourceKey));
}
}
public void TestActivityTrackingOptions_ShouldAddTagsAndBaggageAsOneScopeAndTraceIdAsOtherScope_WhenTagsBaggageAndTraceIdOptionAreSet()
{
var loggerProvider = new ExternalScopeLoggerProvider();
var loggerFactory = LoggerFactory.Create(builder =>
{
builder
.Configure(o => o.ActivityTrackingOptions = ActivityTrackingOptions.TraceId | ActivityTrackingOptions.Baggage | ActivityTrackingOptions.Tags)
.AddProvider(loggerProvider);
});
var logger = loggerFactory.CreateLogger("Logger");
Activity activity = new Activity("ScopeActivity");
activity.AddTag("testTagKey1", "testTagValue");
activity.AddBaggage("testBaggageKey1", "testBaggageValue");
activity.Start();
logger.LogInformation("Message1");
string traceIdActivityLogString = GetActivityLogString(ActivityTrackingOptions.TraceId);
activity.Stop();
Assert.Equal("Message1", loggerProvider.LogText[0]);
Assert.Equal(traceIdActivityLogString, loggerProvider.LogText[1]);
Assert.Equal("testTagKey1:testTagValue", loggerProvider.LogText[2]);
Assert.Equal("testBaggageKey1:testBaggageValue", loggerProvider.LogText[3]);
}
