public Task CollectAsync(ReplicaInfo replicaInfo, CancellationToken cancellationToken)
{
// The diagnostic collection process does lots of synchronous processing. Explicitly
// create a thread so we don't starve thread pool.
var tcs = new TaskCompletionSource <object?>();
var thread = new Thread(() =>
{
try
{
Collect(replicaInfo, cancellationToken);
tcs.SetResult(null);
}
catch (OperationCanceledException)
{
tcs.SetCanceled();
}
catch (Exception ex)
{
tcs.SetException(ex);
}
});
thread.Start();
return(tcs.Task);
}
private static int?SelectProcess(ReplicaInfo replicaInfo)
{
var processIds = DiagnosticsClient.GetPublishedProcesses();
var processes = processIds.Select(pid =>
{
try
{
return(Process.GetProcessById(pid));
}
catch (Exception) // Can fail due to timing.
{
return(null);
}
})
.Where(p => p is object)
.ToArray();
try
{
return(replicaInfo.Selector.Invoke(processes !)?.Id);
}
finally
{
foreach (var process in processes !)
{
process !.Dispose();
}
}
}
public IDisposable Attach(EventPipeEventSource source, ReplicaInfo replicaInfo)
{
var loggerFactory = LoggerFactory.Create(builder => ConfigureLogging(replicaInfo.Service, replicaInfo.Replica, builder));
var lastFormattedMessage = "";
var logActivities = new Dictionary <Guid, LogActivityItem>();
var stack = new Stack <Guid>();
source.Dynamic.AddCallbackForProviderEvent(MicrosoftExtensionsLoggingProviderName, "ActivityJsonStart/Start", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// TODO: Store this information by logger factory id
var item = new LogActivityItem(traceEvent.ActivityID, new LogObject(JsonDocument.Parse(argsJson).RootElement));
if (stack.TryPeek(out var parentId) && logActivities.TryGetValue(parentId, out var parentItem))
{
item.Parent = parentItem;
}
stack.Push(traceEvent.ActivityID);
logActivities[traceEvent.ActivityID] = item;
});
public IDisposable Attach(EventPipeEventSource source, ReplicaInfo replicaInfo)
{
var store = replicaInfo.Metrics;
source.Dynamic.All += traceEvent =>
{
try
{
// Metrics
if (traceEvent.EventName.Equals("EventCounters"))
{
var value = (IDictionary <string, object>)traceEvent.PayloadValue(0);
var eventPayload = (IDictionary <string, object>)value["Payload"];
var payload = CounterPayload.FromPayload(eventPayload);
store[traceEvent.ProviderName + "/" + payload.Name] = payload.Value;
}
}
catch (Exception ex)
{
_logger.LogError(ex, "Error processing counter for {ProviderName}:{EventName}", traceEvent.ProviderName, traceEvent.EventName);
}
};
return(new NullDisposable());
}
private SpanExporter?CreateSpanExporter(ReplicaInfo replicaInfo)
{
if (string.Equals(_provider.Key, "zipkin", StringComparison.OrdinalIgnoreCase) &&
!string.IsNullOrEmpty(_provider.Value))
{
var zipkin = new ZipkinTraceExporter(new ZipkinTraceExporterOptions()
{
ServiceName = replicaInfo.Service,
Endpoint = new Uri($"{_provider.Value.TrimEnd('/')}/api/v2/spans")
});
return(zipkin);
}
// TODO: Support Jaegar
// TODO: Support ApplicationInsights
return(null);
}
public IDisposable Attach(EventPipeEventSource source, ReplicaInfo replicaInfo)
{
var exporter = CreateSpanExporter(replicaInfo);
if (exporter is null)
{
return(new NullDisposable());
}
var processor = new SimpleSpanProcessor(exporter);
var activities = new Dictionary <string, ActivityItem>();
source.Dynamic.All += traceEvent =>
{
if (traceEvent.EventName == "Activity1Start/Start")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
if (TryCreateActivity(arguments, out var item))
{
string?method = null;
string?path = null;
string?host = null;
string?pathBase = null;
string?queryString = null;
string?scheme = null;
foreach (var arg in arguments)
{
var key = (string)arg["Key"];
var value = (string)arg["Value"];
if (key == "Path")
{
path = value;
}
else if (key == "Method")
{
method = value;
}
else if (key == "Host")
{
host = value;
}
else if (key == "PathBase")
{
pathBase = value;
}
else if (key == "Scheme")
{
scheme = value;
}
else if (key == "QueryString")
{
queryString = value;
}
}
item.Name = path;
item.Kind = SpanKind.Server;
item.Attributes[SpanAttributeConstants.HttpUrlKey] = scheme + "://" + host + pathBase + path + queryString;
item.Attributes[SpanAttributeConstants.HttpMethodKey] = method;
item.Attributes[SpanAttributeConstants.HttpPathKey] = path;
activities[item.Id] = item;
}
}
}
if (traceEvent.EventName == "Activity1Stop/Stop")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
var(activityId, duration) = GetActivityStop(arguments);
var statusCode = 0;
foreach (var arg in arguments)
{
var key = (string)arg["Key"];
var value = (string)arg["Value"];
if (key == "StatusCode")
{
statusCode = int.Parse(value);
}
}
if (activityId != null && activities.TryGetValue(activityId, out var item))
{
item.Attributes[SpanAttributeConstants.HttpStatusCodeKey] = statusCode;
item.EndTime = item.StartTime + duration;
var spanData = new SpanData(item.Name,
new SpanContext(item.TraceId, item.SpanId, ActivityTraceFlags.Recorded),
item.ParentSpanId,
item.Kind,
item.StartTime,
item.Attributes,
Enumerable.Empty <Event>(),
Enumerable.Empty <Link>(),
null,
Status.Ok,
item.EndTime);
processor.OnEnd(spanData);
activities.Remove(activityId);
}
}
}
if (traceEvent.EventName == "Activity2Start/Start")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
string?uri = null;
string?method = null;
foreach (var arg in arguments)
{
var key = (string)arg["Key"];
var value = (string)arg["Value"];
if (key == "RequestUri")
{
uri = value;
}
else if (key == "Method")
{
method = value;
}
}
if (TryCreateActivity(arguments, out var item))
{
item.Name = uri;
item.Kind = SpanKind.Client;
item.Attributes[SpanAttributeConstants.HttpUrlKey] = uri;
item.Attributes[SpanAttributeConstants.HttpMethodKey] = method;
activities[item.Id] = item;
}
}
}
if (traceEvent.EventName == "Activity2Stop/Stop")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
var(activityId, duration) = GetActivityStop(arguments);
if (activityId != null && activities.TryGetValue(activityId, out var item))
{
item.EndTime = item.StartTime + duration;
var spanData = new SpanData(
item.Name,
new SpanContext(item.TraceId, item.SpanId, ActivityTraceFlags.Recorded),
item.ParentSpanId,
item.Kind,
item.StartTime,
item.Attributes,
Enumerable.Empty <Event>(),
Enumerable.Empty <Link>(),
null,
Status.Ok,
item.EndTime);
processor.OnEnd(spanData);
activities.Remove(activityId);
}
}
}
};
return(new NullDisposable());
}
public void Collect(ReplicaInfo replicaInfo, CancellationToken cancellationToken)
{
var start = DateTime.UtcNow;
var processId = (int?)null;
while (DateTime.UtcNow < start + SelectProcessTimeout && !cancellationToken.IsCancellationRequested)
{
processId = SelectProcess(replicaInfo);
if (processId.HasValue)
{
_logger.LogInformation("Selected process {PID}.", processId);
break;
}
Thread.Sleep(500);
}
if (processId is null)
{
_logger.LogInformation("Failed to collect diagnostics for {ServiceName} after {Timeout}.", replicaInfo.Replica, SelectProcessTimeout);
return;
}
// When we get here we've chosen the desired process.
_logger.LogInformation("Listening for event pipe events for {ServiceName} on process id {PID}", replicaInfo.Replica, processId);
var providers = CreateDefaultProviders();
providers.Add(CreateStandardProvider(replicaInfo.AssemblyName));
while (!cancellationToken.IsCancellationRequested)
{
var session = (EventPipeSession?)null;
var client = new DiagnosticsClient(processId.Value);
try
{
session = client.StartEventPipeSession(providers);
}
// If the process has already exited, a ServerNotAvailableException will be thrown.
catch (Exception)
{
break;
}
void StopSession()
{
try
{
session?.Stop();
}
catch (EndOfStreamException)
{
// If the app we're monitoring exits abruptly, this may throw in which case we just swallow the exception and exit gracefully.
}
// We may time out if the process ended before we sent StopTracing command. We can just exit in that case.
catch (TimeoutException)
{
}
// On Unix platforms, we may actually get a PNSE since the pipe is gone with the process, and Runtime Client Library
// does not know how to distinguish a situation where there is no pipe to begin with, or where the process has exited
// before dotnet-counters and got rid of a pipe that once existed.
// Since we are catching this in StopMonitor() we know that the pipe once existed (otherwise the exception would've
// been thrown in StartMonitor directly)
catch (PlatformNotSupportedException)
{
}
// If the process has already exited, a ServerNotAvailableException will be thrown.
// This can always race with tye shutting down and a process being restarted on exiting.
catch (ServerNotAvailableException)
{
}
}
using var _ = cancellationToken.Register(() => StopSession());
var disposables = new List <IDisposable>();
try
{
var source = new EventPipeEventSource(session.EventStream);
// Distributed Tracing
if (TracingSink is object)
{
disposables.Add(TracingSink.Attach(source, replicaInfo));
}
// Metrics
if (MetricSink is object)
{
disposables.Add(MetricSink.Attach(source, replicaInfo));
}
// Logging
if (LoggingSink is object)
{
disposables.Add(LoggingSink.Attach(source, replicaInfo));
}
source.Process();
}
catch (DiagnosticsClientException ex)
{
_logger.LogDebug(0, ex, "Failed to start the event pipe session");
}
catch (Exception)
{
// This fails if stop is called or if the process dies
}
finally
{
session?.Dispose();
foreach (var disposable in disposables)
{
disposable.Dispose();
}
}
}
_logger.LogInformation("Event pipe collection completed for {ServiceName} on process id {PID}", replicaInfo.Replica, processId);
}
