private void InternalUnobservedTaskExceptionHandler(object sender, UnobservedTaskExceptionEventArgs e)
{
var aggrException = e.Exception;
var baseException = aggrException.GetBaseException();
var tplTask = (Task)sender;
var contextObj = tplTask.AsyncState;
var context = contextObj as ISchedulingContext;
try
{
UnobservedExceptionHandler(context, baseException);
}
finally
{
if (e.Observed)
{
logger.Info(ErrorCode.Runtime_Error_100311, "Silo caught an UnobservedTaskException which was successfully observed and recovered from. BaseException = {0}. Exception = {1}",
baseException.Message, LogFormatter.PrintException(aggrException));
}
else
{
var errorStr = String.Format("Silo Caught an UnobservedTaskException event sent by {0}. Exception = {1}",
OrleansTaskExtentions.ToString((Task)sender), LogFormatter.PrintException(aggrException));
logger.Error(ErrorCode.Runtime_Error_100005, errorStr);
logger.Error(ErrorCode.Runtime_Error_100006, "Exception remained UnObserved!!! The subsequent behavior depends on the ThrowUnobservedTaskExceptions setting in app config and .NET version.");
}
}
}
public void Close()
{
if (_logOutput == null)
{
return; // was already closed.
}
try
{
lock (_lockObj)
{
if (_logOutput == null) // was already closed.
{
return;
}
_logOutput.Flush();
_logOutput.Dispose();
_logOutput = null;
}
}
catch (Exception exc)
{
var msg = string.Format("Ignoring error closing log file {0} - {1}", _logFileName,
LogFormatter.PrintException(exc));
Console.WriteLine(msg);
}
finally
{
_logOutput = null;
_logFileName = null;
}
}
public void OnFatalException(object sender, string context, Exception exception)
{
this.log.LogError(
(int)ErrorCode.Logger_ProcessCrashing,
exception,
"Fatal error from {Sender}. Context: {Context}",
sender,
context);
var msg = $"FATAL EXCEPTION from {sender?.ToString() ?? "null"}. Context: {context ?? "null"}. "
+ $"Exception: {(exception != null ? LogFormatter.PrintException(exception) : "null")}.\n"
+ $"Current stack: {Environment.StackTrace}";
Console.Error.WriteLine(msg);
// Allow some time for loggers to flush.
Thread.Sleep(2000);
if (Debugger.IsAttached)
{
Debugger.Break();
}
Environment.FailFast(msg, exception);
}
private void InternalUnobservedTaskExceptionHandler(object sender, System.Threading.Tasks.UnobservedTaskExceptionEventArgs e)
{
var aggrException = e.Exception;
var baseException = aggrException.GetBaseException();
var context = (sender as Task)?.AsyncState;
try
{
this.logger.LogError((int)ErrorCode.Runtime_Error_100104, baseException, "Silo caught an unobserved exception thrown from context {Context}: {Exception}", context, baseException);
}
finally
{
if (e.Observed)
{
logger.Info(ErrorCode.Runtime_Error_100311, "Silo caught an unobserved exception which was successfully observed and recovered from. BaseException = {0}. Exception = {1}",
baseException.Message, LogFormatter.PrintException(aggrException));
}
else
{
var errorStr = String.Format("Silo Caught an UnobservedTaskException event sent by {0}. Exception = {1}",
OrleansTaskExtentions.ToString((Task)sender), LogFormatter.PrintException(aggrException));
logger.Error(ErrorCode.Runtime_Error_100005, errorStr);
logger.Error(ErrorCode.Runtime_Error_100006, "Exception remained UnObserved!!! The subsequent behavior depends on the ThrowUnobservedTaskExceptions setting in app config and .NET version.");
}
}
}
public void OnFatalException(object sender, string context, Exception exception)
{
this.log.LogError(
(int)ErrorCode.Logger_ProcessCrashing,
exception,
"Fatal error from {Sender}. Context: {Context}",
sender,
context);
if (!this.clusterMembershipOptions.IsRunningAsUnitTest)
{
var msg = $"FATAL EXCEPTION from {sender?.ToString() ?? "null"}. Context: {context ?? "null"}. "
+ $"Exception: {(exception != null ? LogFormatter.PrintException(exception) : "null")}.\n"
+ $"Current stack: {Environment.StackTrace}";
Console.Error.WriteLine(msg);
// Allow some time for loggers to flush.
Thread.Sleep(2000);
if (Debugger.IsAttached)
{
Debugger.Break();
}
Environment.FailFast(msg, exception);
}
else
{
this.log.LogWarning(
$"{nameof(ClusterMembershipOptions)}.{nameof(ClusterMembershipOptions.IsRunningAsUnitTest)} is set."
+ " The process will not be terminated.");
}
}
private static string FormatLogMessage_Impl(
DateTime timestamp,
Severity severity,
LoggerType loggerType,
string caller,
string message,
IPEndPoint myIPEndPoint,
Exception exception,
int errorCode,
bool includeStackTrace)
{
if (severity == Severity.Error)
{
message = "!!!!!!!!!! " + message;
}
string ip = myIPEndPoint == null ? String.Empty : myIPEndPoint.ToString();
if (loggerType.Equals(LoggerType.Grain))
{
// Grain identifies itself, so I don't want an additional long string in the prefix.
// This is just a temporal solution to ease the dev. process, can remove later.
ip = String.Empty;
}
string exc = includeStackTrace ? LogFormatter.PrintException(exception) : LogFormatter.PrintExceptionWithoutStackTrace(exception);
string msg = String.Format("[{0} {1,5}\t{2}\t{3}\t{4}\t{5}]\t{6}\t{7}",
LogManager.ShowDate ? LogFormatter.PrintDate(timestamp) : LogFormatter.PrintTime(timestamp), //0
Thread.CurrentThread.ManagedThreadId, //1
LogManager.SeverityTable[(int)severity], //2
errorCode, //3
caller, //4
ip, //5
message, //6
exc); //7
return(msg);
}
public async Task Invoke(IAddressable target, IInvokable invokable, Message message)
{
try
{
// Don't process messages that have already timed out
if (message.IsExpired)
{
this.messagingTrace.OnDropExpiredMessage(message, MessagingStatisticsGroup.Phase.Invoke);
return;
}
RequestContextExtensions.Import(message.RequestContextData);
if (schedulingOptions.PerformDeadlockDetection && !message.TargetGrain.IsSystemTarget)
{
UpdateDeadlockInfoInRequestContext(new RequestInvocationHistory(message.TargetGrain, message.TargetActivation, message.DebugContext));
// RequestContext is automatically saved in the msg upon send and propagated to the next hop
// in RuntimeClient.CreateMessage -> RequestContextExtensions.ExportToMessage(message);
}
bool startNewTransaction = false;
ITransactionInfo transactionInfo = message.TransactionInfo;
if (message.IsTransactionRequired && transactionInfo == null)
{
// TODO: this should be a configurable parameter
var transactionTimeout = Debugger.IsAttached ? TimeSpan.FromMinutes(30) : TimeSpan.FromSeconds(10);
// Start a new transaction
transactionInfo = await this.transactionAgent.StartTransaction(message.IsReadOnly, transactionTimeout);
startNewTransaction = true;
}
if (transactionInfo != null)
{
TransactionContext.SetTransactionInfo(transactionInfo);
}
object resultObject;
try
{
var request = (InvokeMethodRequest)message.BodyObject;
if (request.Arguments != null)
{
CancellationSourcesExtension.RegisterCancellationTokens(target, request, this.loggerFactory, logger, this, this.cancellationTokenRuntime);
}
var invoker = invokable.GetInvoker(typeManager, request.InterfaceId, message.GenericGrainType);
if (invoker is IGrainExtensionMethodInvoker &&
!(target is IGrainExtension) &&
!TryInstallExtension(request.InterfaceId, invokable, message.GenericGrainType, ref invoker))
{
// We are trying the invoke a grain extension method on a grain
// -- most likely reason is that the dynamic extension is not installed for this grain
// So throw a specific exception here rather than a general InvalidCastException
var error = String.Format(
"Extension not installed on grain {0} attempting to invoke type {1} from invokable {2}",
target.GetType().FullName, invoker.GetType().FullName, invokable.GetType().FullName);
var exc = new GrainExtensionNotInstalledException(error);
string extraDebugInfo = null;
#if DEBUG
extraDebugInfo = Utils.GetStackTrace();
#endif
this.logger.Warn(ErrorCode.Stream_ExtensionNotInstalled,
string.Format("{0} for message {1} {2}", error, message, extraDebugInfo), exc);
throw exc;
}
messagingTrace.OnInvokeMessage(message);
var requestInvoker = new GrainMethodInvoker(target, request, invoker, GrainCallFilters, interfaceToImplementationMapping);
await requestInvoker.Invoke();
resultObject = requestInvoker.Result;
}
catch (Exception exc1)
{
if (message.Direction == Message.Directions.OneWay)
{
this.invokeExceptionLogger.Warn(ErrorCode.GrainInvokeException,
"Exception during Grain method call of message: " + message + ": " + LogFormatter.PrintException(exc1), exc1);
}
else if (invokeExceptionLogger.IsEnabled(LogLevel.Debug))
{
this.invokeExceptionLogger.Debug(ErrorCode.GrainInvokeException,
"Exception during Grain method call of message: " + message + ": " + LogFormatter.PrintException(exc1), exc1);
}
if (transactionInfo != null)
{
transactionInfo.ReconcilePending();
// Record reason for abort, if not alread set
transactionInfo.RecordException(exc1, serializationManager);
if (startNewTransaction)
{
exc1 = transactionInfo.MustAbort(serializationManager);
await this.transactionAgent.Abort(transactionInfo);
TransactionContext.Clear();
}
}
// If a grain allowed an inconsistent state exception to escape and the exception originated from
// this activation, then deactivate it.
var ise = exc1 as InconsistentStateException;
if (ise != null && ise.IsSourceActivation)
{
// Mark the exception so that it doesn't deactivate any other activations.
ise.IsSourceActivation = false;
var activation = (target as Grain)?.Data;
if (activation != null)
{
this.invokeExceptionLogger.Info($"Deactivating {activation} due to inconsistent state.");
this.DeactivateOnIdle(activation.ActivationId);
}
}
if (message.Direction != Message.Directions.OneWay)
{
SafeSendExceptionResponse(message, exc1);
}
return;
}
OrleansTransactionException transactionException = null;
if (transactionInfo != null)
{
try
{
transactionInfo.ReconcilePending();
transactionException = transactionInfo.MustAbort(serializationManager);
// This request started the transaction, so we try to commit before returning,
// or if it must abort, tell participants that it aborted
if (startNewTransaction)
{
try
{
if (transactionException == null)
{
var status = await this.transactionAgent.Resolve(transactionInfo);
if (status != TransactionalStatus.Ok)
{
transactionException = status.ConvertToUserException(transactionInfo.Id);
}
}
else
{
await this.transactionAgent.Abort(transactionInfo);
}
}
finally
{
TransactionContext.Clear();
}
}
}
catch (Exception e)
{
// we should never hit this, but if we do, the following message will help us diagnose
this.logger.LogError(e, "Error in transaction post-grain-method-invocation code");
throw;
}
}
if (message.Direction != Message.Directions.OneWay)
{
if (transactionException != null)
{
SafeSendExceptionResponse(message, transactionException);
}
else
{
SafeSendResponse(message, resultObject);
}
}
return;
}
catch (Exception exc2)
{
this.logger.Warn(ErrorCode.Runtime_Error_100329, "Exception during Invoke of message: " + message, exc2);
TransactionContext.Clear();
if (message.Direction != Message.Directions.OneWay)
{
SafeSendExceptionResponse(message, exc2);
}
}
finally
{
TransactionContext.Clear();
}
}
private static bool IsCompatibleWithCurrentProcess(string fileName, out string[] complaints)
{
complaints = null;
Stream peImage = null;
try
{
peImage = File.Open(fileName, FileMode.Open, FileAccess.Read, FileShare.Read);
using (var peReader = new PEReader(peImage, PEStreamOptions.PrefetchMetadata))
{
peImage = null;
if (peReader.HasMetadata)
{
var processorArchitecture = ProcessorArchitecture.MSIL;
var isPureIL = (peReader.PEHeaders.CorHeader.Flags & CorFlags.ILOnly) != 0;
if (peReader.PEHeaders.PEHeader.Magic == PEMagic.PE32Plus)
{
processorArchitecture = ProcessorArchitecture.Amd64;
}
else if ((peReader.PEHeaders.CorHeader.Flags & CorFlags.Requires32Bit) != 0 || !isPureIL)
{
processorArchitecture = ProcessorArchitecture.X86;
}
var isLoadable = (isPureIL && processorArchitecture == ProcessorArchitecture.MSIL) ||
(Environment.Is64BitProcess && processorArchitecture == ProcessorArchitecture.Amd64) ||
(!Environment.Is64BitProcess && processorArchitecture == ProcessorArchitecture.X86);
if (!isLoadable)
{
complaints = new[] { $"The file {fileName} is not loadable into this process, either it is not an MSIL assembly or the compliled for a different processor architecture." };
}
return(isLoadable);
}
else
{
complaints = new[] { $"The file {fileName} does not contain any CLR metadata, probably it is a native file." };
return(false);
}
}
}
catch (IOException)
{
return(false);
}
catch (BadImageFormatException)
{
return(false);
}
catch (UnauthorizedAccessException)
{
return(false);
}
catch (MissingMethodException)
{
complaints = new[] { "MissingMethodException occured. Please try to add a BindingRedirect for System.Collections.ImmutableCollections to the App.config file to correct this error." };
return(false);
}
catch (Exception ex)
{
complaints = new[] { LogFormatter.PrintException(ex) };
return(false);
}
finally
{
peImage?.Dispose();
}
}
public async Task Invoke(IGrainContext target, Message message)
{
try
{
// Don't process messages that have already timed out
if (message.IsExpired)
{
this.messagingTrace.OnDropExpiredMessage(message, MessagingStatisticsGroup.Phase.Invoke);
return;
}
RequestContextExtensions.Import(message.RequestContextData);
bool startNewTransaction = false;
ITransactionInfo transactionInfo = message.TransactionInfo;
if (message.IsTransactionRequired && transactionInfo == null)
{
// TODO: this should be a configurable parameter
var transactionTimeout = Debugger.IsAttached ? TimeSpan.FromMinutes(30) : TimeSpan.FromSeconds(10);
// Start a new transaction
transactionInfo = await this.transactionAgent.StartTransaction(message.IsReadOnly, transactionTimeout);
startNewTransaction = true;
}
if (transactionInfo != null)
{
TransactionContext.SetTransactionInfo(transactionInfo);
}
object resultObject;
try
{
var request = (InvokeMethodRequest)message.BodyObject;
if (request.Arguments != null)
{
CancellationSourcesExtension.RegisterCancellationTokens(target, request);
}
if (!this.invokers.TryGet(message.InterfaceType, out var invoker))
{
throw new KeyNotFoundException($"Could not find an invoker for interface {message.InterfaceType}");
}
messagingTrace.OnInvokeMessage(message);
var requestInvoker = new GrainMethodInvoker(target, request, invoker, GrainCallFilters, interfaceToImplementationMapping);
await requestInvoker.Invoke();
resultObject = requestInvoker.Result;
}
catch (Exception exc1)
{
if (message.Direction == Message.Directions.OneWay)
{
this.invokeExceptionLogger.Warn(ErrorCode.GrainInvokeException,
"Exception during Grain method call of message: " + message + ": " + LogFormatter.PrintException(exc1), exc1);
}
else if (invokeExceptionLogger.IsEnabled(LogLevel.Debug))
{
this.invokeExceptionLogger.Debug(ErrorCode.GrainInvokeException,
"Exception during Grain method call of message: " + message + ": " + LogFormatter.PrintException(exc1), exc1);
}
if (transactionInfo != null)
{
transactionInfo.ReconcilePending();
// Record reason for abort, if not already set.
transactionInfo.RecordException(exc1, serializationManager);
if (startNewTransaction)
{
exc1 = transactionInfo.MustAbort(serializationManager);
await this.transactionAgent.Abort(transactionInfo);
TransactionContext.Clear();
}
}
// If a grain allowed an inconsistent state exception to escape and the exception originated from
// this activation, then deactivate it.
var ise = exc1 as InconsistentStateException;
if (ise != null && ise.IsSourceActivation)
{
// Mark the exception so that it doesn't deactivate any other activations.
ise.IsSourceActivation = false;
this.invokeExceptionLogger.Info($"Deactivating {target} due to inconsistent state.");
this.DeactivateOnIdle(target.ActivationId);
}
if (message.Direction != Message.Directions.OneWay)
{
SafeSendExceptionResponse(message, exc1);
}
return;
}
OrleansTransactionException transactionException = null;
if (transactionInfo != null)
{
try
{
transactionInfo.ReconcilePending();
transactionException = transactionInfo.MustAbort(serializationManager);
// This request started the transaction, so we try to commit before returning,
// or if it must abort, tell participants that it aborted
if (startNewTransaction)
{
try
{
if (transactionException is null)
{
var(status, exception) = await this.transactionAgent.Resolve(transactionInfo);
if (status != TransactionalStatus.Ok)
{
transactionException = status.ConvertToUserException(transactionInfo.Id, exception);
}
}
else
{
await this.transactionAgent.Abort(transactionInfo);
}
}
finally
{
TransactionContext.Clear();
}
}
}
catch (Exception e)
{
// we should never hit this, but if we do, the following message will help us diagnose
this.logger.LogError(e, "Error in transaction post-grain-method-invocation code");
throw;
}
}
if (message.Direction != Message.Directions.OneWay)
{
if (transactionException != null)
{
SafeSendExceptionResponse(message, transactionException);
}
else
{
SafeSendResponse(message, resultObject);
}
}
return;
}
catch (Exception exc2)
{
this.logger.Warn(ErrorCode.Runtime_Error_100329, "Exception during Invoke of message: " + message, exc2);
TransactionContext.Clear();
if (message.Direction != Message.Directions.OneWay)
{
SafeSendExceptionResponse(message, exc2);
}
}
finally
{
RequestContext.Clear();
}
}
public static IEnumerable <TypeInfo> GetDefinedTypes(Assembly assembly, ILogger logger = null)
{
try
{
return(assembly.DefinedTypes);
}
catch (Exception exception)
{
if (logger != null && logger.IsEnabled(LogLevel.Warning))
{
var message =
$"Exception loading types from assembly '{assembly.FullName}': {LogFormatter.PrintException(exception)}.";
logger.Warn(ErrorCode.Loader_TypeLoadError_5, message, exception);
}
var typeLoadException = exception as ReflectionTypeLoadException;
if (typeLoadException != null)
{
return(typeLoadException.Types?.Where(type => type != null).Select(type => type.GetTypeInfo()) ??
Enumerable.Empty <TypeInfo>());
}
return(Enumerable.Empty <TypeInfo>());
}
}
public static IEnumerable <TypeInfo> GetDefinedTypes(Assembly assembly, Logger logger)
{
try
{
return(assembly.DefinedTypes);
}
catch (Exception exception)
{
var typeLoadException = exception as ReflectionTypeLoadException;
if (typeLoadException != null)
{
if (typeLoadException.LoaderExceptions != null)
{
//
// If we've only BadImageFormatExceptions in LoaderExceptions, then it's ok to not to log, otherwise log
// as a warning.
//
if (logger != null && logger.IsWarning)
{
if (typeLoadException.LoaderExceptions.Any(ex => !(ex is BadImageFormatException)) || logger.IsVerbose)
{
var message =
$"Exception loading types from assembly '{assembly.FullName}': {LogFormatter.PrintException(exception)}.";
logger.Warn(ErrorCode.Loader_TypeLoadError_5, message, exception);
}
}
}
return(typeLoadException.Types?.Where(type => type != null).Select(type => type.GetTypeInfo()) ??
Enumerable.Empty <TypeInfo>());
}
if (logger != null && logger.IsWarning)
{
var message =
$"Exception loading types from assembly '{assembly.FullName}': {LogFormatter.PrintException(exception)}.";
logger.Warn(ErrorCode.Loader_TypeLoadError_5, message, exception);
}
return(Enumerable.Empty <TypeInfo>());
}
}