/// <summary>
/// Loads a logger from its assembly, instantiates it, and handles errors.
/// </summary>
/// <returns>Instantiated logger.</returns>
private ILogger CreateLogger(bool forwardingLogger)
{
ILogger logger = null;
try
{
if (forwardingLogger)
{
// load the logger from its assembly
LoadedType loggerClass = (new TypeLoader(s_forwardingLoggerClassFilter)).Load(_loggerClassName, _loggerAssembly);
if (loggerClass != null)
{
// instantiate the logger
logger = (IForwardingLogger)Activator.CreateInstance(loggerClass.Type);
}
}
else
{
// load the logger from its assembly
LoadedType loggerClass = (new TypeLoader(s_loggerClassFilter)).Load(_loggerClassName, _loggerAssembly);
if (loggerClass != null)
{
// instantiate the logger
logger = (ILogger)Activator.CreateInstance(loggerClass.Type);
}
}
}
catch (InvalidCastException e)
{
// The logger when trying to load has hit an invalid case, this is usually due to the framework assembly being a different version
string message = ResourceUtilities.FormatResourceString("LoggerInstantiationFailureErrorInvalidCast", _loggerClassName, _loggerAssembly.AssemblyLocation, e.Message);
throw new LoggerException(message, e.InnerException);
}
catch (TargetInvocationException e)
{
// At this point, the interesting stack is the internal exception;
// the outer exception is System.Reflection stuff that says nothing
// about the nature of the logger failure.
Exception innerException = e.InnerException;
if (innerException is LoggerException)
{
// Logger failed politely during construction. In order to preserve
// the stack trace at which the error occured we wrap the original
// exception instead of throwing.
LoggerException l = ((LoggerException)innerException);
throw new LoggerException(l.Message, innerException, l.ErrorCode, l.HelpKeyword);
}
else
{
throw;
}
}
return(logger);
}
public static IEnumerable <Tuple <CommandBarControl, CommandBarPopup[]> > EnumDescendantControls(
[NotNull] this CommandBar root, [NotNull] CompoundException cex)
{
if (root == null)
{
throw new ArgumentNullException(nameof(root));
}
if (cex == null)
{
throw new ArgumentNullException(nameof(cex));
}
var queueEnumChildren =
new Queue <Tuple <CommandBar, CommandBarPopup[]> >(new[]
{ Tuple.Create(root, EmptyArray <CommandBarPopup> .Instance) });
int nBar = -1;
while (queueEnumChildren.Any())
{
Tuple <CommandBar, CommandBarPopup[]> tuple = queueEnumChildren.Dequeue();
nBar++;
List <CommandBarControl> children = null;
try
{
// All children
children = tuple.Item1.Controls.OfType <CommandBarControl>().ToList();
// EnqueueJob child containers
var popups = children.OfType <CommandBarPopup>()
.Select(popup => Tuple.Create(popup.CommandBar, tuple.Item2.Concat(popup).ToArray()));
foreach (var popup in popups)
{
queueEnumChildren.Enqueue(popup);
}
}
catch (Exception e)
{
var ex = new LoggerException("Failed to enum command bar child controls.", e);
ex.AddData("IndexInQueue", () => nBar);
ex.AddData("CommandBarName", () => tuple.Item1.Name);
ex.AddData("CommandBarIndexProperty", () => tuple.Item1.Index);
cex.Exceptions.Add(ex);
}
// Emit
if (children != null) // Null if were exceptions (cannot yield from a catch)
{
foreach (CommandBarControl child in children)
{
yield return(Tuple.Create(child, tuple.Item2));
}
}
}
}
public void CtorMessageTest()
{
LoggerException le;
string message = "message";
le = new LoggerException(message);
Assert.AreEqual(message, le.Message, "Message");
Assert.AreEqual(null, le.ErrorCode, "ErrorCode");
Assert.AreEqual(null, le.HelpKeyword, "HelpKeyword");
}
/// <summary>
/// Loads a logger from its assembly, instantiates it, and handles errors.
/// </summary>
/// <returns>Instantiated logger.</returns>
private ILogger CreateLogger(bool forwardingLogger)
{
ILogger logger = null;
try
{
if (forwardingLogger)
{
// load the logger from its assembly
LoadedType loggerClass = (new TypeLoader(forwardingLoggerClassFilter)).Load(loggerClassName, loggerAssembly);
if (loggerClass != null)
{
// instantiate the logger
logger = (IForwardingLogger)Activator.CreateInstance(loggerClass.Type);
}
}
else
{
// load the logger from its assembly
LoadedType loggerClass = (new TypeLoader(loggerClassFilter)).Load(loggerClassName, loggerAssembly);
if (loggerClass != null)
{
// instantiate the logger
logger = (ILogger)Activator.CreateInstance(loggerClass.Type);
}
}
}
catch (TargetInvocationException e)
{
// At this point, the interesting stack is the internal exception;
// the outer exception is System.Reflection stuff that says nothing
// about the nature of the logger failure.
Exception innerException = e.InnerException;
if (innerException is LoggerException)
{
// Logger failed politely during construction. In order to preserve
// the stack trace at which the error occurred we wrap the original
// exception instead of throwing.
LoggerException l = ((LoggerException)innerException);
throw new LoggerException(l.Message, innerException, l.ErrorCode, l.HelpKeyword);
}
else
{
throw;
}
}
return(logger);
}
public void CtorMessageExceptionTest()
{
LoggerException le;
string message = "message";
Exception e = new Exception("Inner exception message");
le = new LoggerException(message, e);
Assert.AreEqual(message, le.Message, "Message");
Assert.AreEqual(e, le.InnerException, "InnerException");
Assert.AreEqual(null, le.ErrorCode, "ErrorCode");
Assert.AreEqual(null, le.HelpKeyword, "HelpKeyword");
}
public void CtorMessageExceptionCodeTest()
{
LoggerException le;
string message = "message";
string errorCode = "CS0000";
string helpKeyword = "helpKeyword";
Exception e = new Exception("Inner exception message");
le = new LoggerException(message, e, errorCode, helpKeyword);
Assert.AreEqual(message, le.Message, "Message");
Assert.AreEqual(e, le.InnerException, "InnerException");
Assert.AreEqual(errorCode, le.ErrorCode, "ErrorCode");
Assert.AreEqual(helpKeyword, le.HelpKeyword, "HelpKeyword");
}
public void TestGetObjectData2()
{
StreamingContext sc = new StreamingContext();
SerializationInfo si = new SerializationInfo(typeof(LoggerException), new FormatterConverter());
LoggerException le;
string message = "message";
string errorCode = "CS0000";
string helpKeyword = "helpKeyword";
Exception e = new Exception("Inner exception message");
le = new LoggerException(message, e, errorCode, helpKeyword);
le.GetObjectData(si, sc);
Assert.AreEqual(errorCode, si.GetString("errorCode"), "A1");
Assert.AreEqual(helpKeyword, si.GetString("helpKeyword"), "A2");
}
public void SerializeDeserialize2()
{
LoggerException e = new LoggerException("message");
using (MemoryStream memstr = new MemoryStream())
{
BinaryFormatter frm = new BinaryFormatter();
frm.Serialize(memstr, e);
memstr.Position = 0;
LoggerException e2 = (LoggerException)frm.Deserialize(memstr);
e2.ErrorCode.ShouldBeNull();
e2.HelpKeyword.ShouldBeNull();
e2.Message.ShouldBe(e.Message);
e2.InnerException.ShouldBeNull();
}
}
public void SerializeDeserialize2()
{
LoggerException e = new LoggerException("message");
using (MemoryStream memstr = new MemoryStream())
{
BinaryFormatter frm = new BinaryFormatter();
frm.Serialize(memstr, e);
memstr.Position = 0;
LoggerException e2 = (LoggerException)frm.Deserialize(memstr);
Assert.Equal(null, e2.ErrorCode);
Assert.Equal(null, e2.HelpKeyword);
Assert.Equal(e.Message, e2.Message);
Assert.Equal(null, e2.InnerException);
}
}
public void TestGetObjectData1()
{
LoggerException le = new LoggerException();
le.GetObjectData(null, new StreamingContext());
}
protected void WebServiceWrite(LoggerException e)
{
StaticWebService.Write(e.Message + Environment.MachineName);
}
public void ProcessEvents(string applicationName,
string serviceName,
int processId,
string replicaName,
ReplicaStatus replica,
CancellationToken cancellationToken)
{
var hasEventPipe = false;
for (int i = 0; i < 10; ++i)
{
if (DiagnosticsClient.GetPublishedProcesses().Contains(processId))
{
hasEventPipe = true;
break;
}
if (cancellationToken.IsCancellationRequested)
{
return;
}
Thread.Sleep(500);
}
if (!hasEventPipe)
{
_logger.LogInformation("Process id {PID}, does not support event pipe", processId);
return;
}
_logger.LogInformation("Listening for event pipe events for {ServiceName} on process id {PID}", replicaName, processId);
// Create the logger factory for this replica
using var loggerFactory = LoggerFactory.Create(builder => ConfigureLogging(serviceName, replicaName, builder));
var processor = new SimpleSpanProcessor(CreateSpanExporter(serviceName, replicaName));
var providers = new List <EventPipeProvider>()
{
// Runtime Metrics
new EventPipeProvider(
SystemRuntimeEventSourceName,
EventLevel.Informational,
(long)ClrTraceEventParser.Keywords.None,
new Dictionary <string, string>()
{
{ "EventCounterIntervalSec", "1" }
}
),
new EventPipeProvider(
MicrosoftAspNetCoreHostingEventSourceName,
EventLevel.Informational,
(long)ClrTraceEventParser.Keywords.None,
new Dictionary <string, string>()
{
{ "EventCounterIntervalSec", "1" }
}
),
new EventPipeProvider(
GrpcAspNetCoreServer,
EventLevel.Informational,
(long)ClrTraceEventParser.Keywords.None,
new Dictionary <string, string>()
{
{ "EventCounterIntervalSec", "1" }
}
),
// Application Metrics
new EventPipeProvider(
applicationName,
EventLevel.Informational,
(long)ClrTraceEventParser.Keywords.None,
new Dictionary <string, string>()
{
{ "EventCounterIntervalSec", "1" }
}
),
// Logging
new EventPipeProvider(
MicrosoftExtensionsLoggingProviderName,
EventLevel.LogAlways,
(long)(LoggingEventSource.Keywords.JsonMessage | LoggingEventSource.Keywords.FormattedMessage)
),
// Distributed Tracing
// Activity correlation
new EventPipeProvider(TplEventSource,
keywords: 0x80,
eventLevel: EventLevel.LogAlways),
// Diagnostic source events
new EventPipeProvider(DiagnosticSourceEventSource,
keywords: 0x1 | 0x2,
eventLevel: EventLevel.Verbose,
arguments: new Dictionary <string, string>
{
{ "FilterAndPayloadSpecs", DiagnosticFilterString }
})
};
while (!cancellationToken.IsCancellationRequested)
{
EventPipeSession session = null;
var client = new DiagnosticsClient(processId);
try
{
session = client.StartEventPipeSession(providers);
}
catch (EndOfStreamException)
{
break;
}
catch (Exception ex)
{
if (!cancellationToken.IsCancellationRequested)
{
_logger.LogDebug(0, ex, "Failed to start the event pipe session");
}
// We can't even start the session, wait until the process boots up again to start another metrics thread
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)
{
}
}
using var _ = cancellationToken.Register(() => StopSession());
try
{
var source = new EventPipeEventSource(session.EventStream);
var activities = new Dictionary <string, ActivityItem>();
source.Dynamic.All += traceEvent =>
{
try
{
// Uncomment to debug the diagnostics source event source
//if (traceEvent.EventName == "Message")
//{
// _logger.LogTrace("[" + replicaName + "]:" + traceEvent.PayloadValue(0));
//}
//// Distributed tracing
// else
if (traceEvent.EventName == "Activity1Start/Start")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
string activityId = null;
string parentId = null;
string operationName = null;
string httpMethod = null;
string path = null;
string spanId = null;
string parentSpanId = null;
string traceId = null;
DateTime startTime = default;
ActivityIdFormat idFormat = default;
foreach (var arg in arguments)
{
var key = (string)arg["Key"];
var value = (string)arg["Value"];
if (key == "ActivityId")
{
activityId = value;
}
else if (key == "ActivityParentId")
{
parentId = value;
}
else if (key == "ActivityOperationName")
{
operationName = value;
}
else if (key == "ActivitySpanId")
{
spanId = value;
}
else if (key == "ActivityTraceId")
{
traceId = value;
}
else if (key == "ActivityParentSpanId")
{
parentSpanId = value;
}
else if (key == "Method")
{
httpMethod = value;
}
else if (key == "Path")
{
path = value;
}
else if (key == "ActivityStartTime")
{
startTime = new DateTime(long.Parse(value), DateTimeKind.Utc);
}
else if (key == "ActivityIdFormat")
{
idFormat = Enum.Parse <ActivityIdFormat>(value);
}
}
if (string.IsNullOrEmpty(activityId))
{
// Not a 3.1 application (we can detect this earlier)
return;
}
if (idFormat == ActivityIdFormat.Hierarchical)
{
// We need W3C to make it work
return;
}
// This is what open telemetry currently does
// https://github.com/open-telemetry/opentelemetry-dotnet/blob/4ba732af062ddc2759c02aebbc91335aaa3f7173/src/OpenTelemetry.Collector.AspNetCore/Implementation/HttpInListener.cs#L65-L92
var item = new ActivityItem()
{
Name = path,
SpanId = ActivitySpanId.CreateFromString(spanId),
TraceId = ActivityTraceId.CreateFromString(traceId),
ParentSpanId = parentSpanId == "0000000000000000" ? default : ActivitySpanId.CreateFromString(parentSpanId),
StartTime = startTime,
};
item.Attributes[SpanAttributeConstants.HttpMethodKey] = httpMethod;
item.Attributes[SpanAttributeConstants.HttpPathKey] = path;
activities[activityId] = item;
}
}
else if (traceEvent.EventName == "Activity1Stop/Stop")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
if (traceEvent.PayloadByName("Arguments") is IDictionary <string, object>[] arguments)
{
string activityId = null;
TimeSpan duration = default;
int statusCode = 0;
foreach (var arg in arguments)
{
var key = (string)arg["Key"];
var value = (string)arg["Value"];
if (key == "ActivityId")
{
activityId = value;
}
else if (key == "StatusCode")
{
statusCode = int.Parse(value);
}
else if (key == "ActivityDuration")
{
duration = new TimeSpan(long.Parse(value));
}
}
if (string.IsNullOrEmpty(activityId))
{
// Not a 3.1 application (we can detect this earlier)
return;
}
if (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,
SpanKind.Server,
item.StartTime,
item.Attributes,
Enumerable.Empty <Event>(),
Enumerable.Empty <Link>(),
null,
Status.Ok,
item.EndTime);
processor.OnEnd(spanData);
activities.Remove(activityId);
}
}
}
else if (traceEvent.EventName == "Activity2Start/Start")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
_logger.LogDebug("[" + replicaName + "]: " + listenerEventName + " fired");
}
else if (traceEvent.EventName == "Activity2Stop/Stop")
{
var listenerEventName = (string)traceEvent.PayloadByName("EventName");
_logger.LogDebug("[" + replicaName + "]: " + listenerEventName + " fired");
}
// Metrics
else if (traceEvent.EventName.Equals("EventCounters"))
{
var payloadVal = (IDictionary <string, object>)traceEvent.PayloadValue(0);
var eventPayload = (IDictionary <string, object>)payloadVal["Payload"];
ICounterPayload payload = CounterPayload.FromPayload(eventPayload);
replica.Metrics[traceEvent.ProviderName + "/" + payload.Name] = payload.Value;
}
}
catch (Exception ex)
{
_logger.LogError(ex, "Error processing counter for {ProviderName}:{EventName}", traceEvent.ProviderName, traceEvent.EventName);
}
};
// Logging
string 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
{
ActivityID = traceEvent.ActivityID,
ScopedObject = 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;
});
source.Dynamic.AddCallbackForProviderEvent(MicrosoftExtensionsLoggingProviderName, "ActivityJsonStop/Stop", (traceEvent) =>
{
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
stack.Pop();
logActivities.Remove(traceEvent.ActivityID);
});
source.Dynamic.AddCallbackForProviderEvent(MicrosoftExtensionsLoggingProviderName, "MessageJson", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, ExceptionJson, ArgumentsJson
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var exceptionJson = (string)traceEvent.PayloadByName("ExceptionJson");
var argsJson = (string)traceEvent.PayloadByName("ArgumentsJson");
// There's a bug that causes some of the columns to get mixed up
if (eventName.StartsWith("{"))
{
argsJson = exceptionJson;
exceptionJson = eventName;
eventName = null;
}
if (string.IsNullOrEmpty(argsJson))
{
return;
}
Exception exception = null;
var logger = loggerFactory.CreateLogger(categoryName);
var scopes = new List <IDisposable>();
if (logActivities.TryGetValue(traceEvent.ActivityID, out var logActivityItem))
{
// REVIEW: Does order matter here? We're combining everything anyways.
while (logActivityItem != null)
{
scopes.Add(logger.BeginScope(logActivityItem.ScopedObject));
logActivityItem = logActivityItem.Parent;
}
}
try
{
if (exceptionJson != "{}")
{
var exceptionMessage = JsonSerializer.Deserialize <JsonElement>(exceptionJson);
exception = new LoggerException(exceptionMessage);
}
var message = JsonSerializer.Deserialize <JsonElement>(argsJson);
if (message.TryGetProperty("{OriginalFormat}", out var formatElement))
{
var formatString = formatElement.GetString();
var formatter = new LogValuesFormatter(formatString);
object[] args = new object[formatter.ValueNames.Count];
for (int i = 0; i < args.Length; i++)
{
args[i] = message.GetProperty(formatter.ValueNames[i]).GetString();
}
logger.Log(logLevel, new EventId(eventId, eventName), exception, formatString, args);
}
else
{
var obj = new LogObject(message, lastFormattedMessage);
logger.Log(logLevel, new EventId(eventId, eventName), obj, exception, LogObject.Callback);
}
}
catch (Exception ex)
{
_logger.LogDebug(ex, "Error processing log entry for {ServiceName}", replicaName);
}
finally
{
scopes.ForEach(d => d.Dispose());
}
});
source.Dynamic.AddCallbackForProviderEvent(MicrosoftExtensionsLoggingProviderName, "FormattedMessage", (traceEvent) =>
{
// Level, FactoryID, LoggerName, EventID, EventName, FormattedMessage
var logLevel = (LogLevel)traceEvent.PayloadByName("Level");
var factoryId = (int)traceEvent.PayloadByName("FactoryID");
var categoryName = (string)traceEvent.PayloadByName("LoggerName");
var eventId = (int)traceEvent.PayloadByName("EventId");
var eventName = (string)traceEvent.PayloadByName("EventName");
var formattedMessage = (string)traceEvent.PayloadByName("FormattedMessage");
if (string.IsNullOrEmpty(formattedMessage))
{
formattedMessage = eventName;
eventName = "";
}
lastFormattedMessage = formattedMessage;
});
source.Process();
}
/// <summary>
/// Retrieves an access token from AAD using the client app credentials.
/// </summary>
/// <param name="tenantId"></param>
/// <returns></returns>
public static string AuthenticateAndGetToken(string tenantId, string authenticationMethod)
{
AuthenticationResult result = null;
// string accessToken;
try
{
AuthenticationContext authContext = new AuthenticationContext(String.Format(AuthorityUrl, tenantId));
try
{
if (authenticationMethod == "Certificate")
{
if ((ConfigurationManager.AppSettings["EncryptionEntropy"] == "") || (ConfigurationManager.AppSettings["EncryptionByteLength"] == ""))
{
Console.WriteLine("Missing Certificate password information. Please enter your certificate password: "******"ClientKey")
{
ClientCredential clientCredentials = new ClientCredential(AADHelper.ClientId, AADHelper.ClientKey);
result = authContext.AcquireToken(AADHelper.ResourceID, clientCredentials);
}
else
{
throw new LoggerException(String.Format("Invalid authentication method: {0}", authenticationMethod));
}
if (result != null)
{
//accessToken = result.AccessToken;
CurrentAccessToken = result.AccessToken;
ExpiresOn = result.ExpiresOn;
if (String.IsNullOrEmpty(CurrentAccessToken))
{
LoggerException logEx = new LoggerException(String.Format("A token was not received from Azure Active Directory with Tenant ID {0}.", tenantId), tenantId);
throw logEx;
}
}
}
catch (AdalException ex)
{
string message = ex.Message;
if (ex.InnerException != null)
{
message += "Inner Exception : " + ex.InnerException.Message;
}
throw new LoggerException("AcquireToken exception: " + message, ex);
}
}
catch (LoggerException ex)
{
throw ex;
}
catch (Exception ex)
{
throw new LoggerException("AuthenticateAndGetToken exception: " + ex.Message, ex);
}
return(result.AccessToken);
}
protected void WebServiceWrite(LoggerException e)
{
StaticWebService.Write(e.Message + Environment.MachineName);
}
