public async Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
foreach (IFunctionInstanceLogger logger in _loggers)
{
await logger.LogFunctionCompletedAsync(message, cancellationToken);
}
}
public async Task <IDelayedException> TryExecuteAsync(IFunctionInstance instance, CancellationToken cancellationToken)
{
FunctionStartedMessage startedMessage = CreateStartedMessageWithoutArguments(instance);
IDictionary <string, ParameterLog> parameterLogCollector = new Dictionary <string, ParameterLog>();
FunctionCompletedMessage completedMessage = null;
ExceptionDispatchInfo exceptionInfo = null;
string startedMessageId = null;
try
{
startedMessageId = await ExecuteWithLogMessageAsync(instance, startedMessage, parameterLogCollector, cancellationToken);
completedMessage = CreateCompletedMessage(startedMessage);
}
catch (Exception exception)
{
if (completedMessage == null)
{
completedMessage = CreateCompletedMessage(startedMessage);
}
completedMessage.Failure = new FunctionFailure
{
Exception = exception,
ExceptionType = exception.GetType().FullName,
ExceptionDetails = exception.ToDetails(),
};
exceptionInfo = ExceptionDispatchInfo.Capture(exception);
}
completedMessage.ParameterLogs = parameterLogCollector;
completedMessage.EndTime = DateTimeOffset.UtcNow;
bool loggedStartedEvent = startedMessageId != null;
CancellationToken logCompletedCancellationToken;
if (loggedStartedEvent)
{
// If function started was logged, don't cancel calls to log function completed.
logCompletedCancellationToken = CancellationToken.None;
}
else
{
logCompletedCancellationToken = cancellationToken;
}
await _functionInstanceLogger.LogFunctionCompletedAsync(completedMessage,
logCompletedCancellationToken);
if (loggedStartedEvent)
{
await _functionInstanceLogger.DeleteLogFunctionStartedAsync(startedMessageId, cancellationToken);
}
return(exceptionInfo != null ? new ExceptionDispatchInfoDelayedException(exceptionInfo) : null);
}
public void CreateFunctionStatusMessage_FunctionComplete_CreatesExpectedMessage()
{
FunctionCompletedMessage completedMessage = new FunctionCompletedMessage
{
Function = new FunctionDescriptor
{
Id = "TestHost.TestFunction"
},
FunctionInstanceId = Guid.NewGuid(),
StartTime = DateTime.Now,
EndTime = DateTime.Now,
OutputBlob = new LocalBlobDescriptor(),
ParameterLogBlob = new LocalBlobDescriptor()
};
FunctionStatusMessage statusMessage = FunctionStatusLogger.CreateFunctionStatusMessage(completedMessage);
Assert.Equal(completedMessage.Function.Id, statusMessage.FunctionId);
Assert.Equal(completedMessage.FunctionInstanceId, statusMessage.FunctionInstanceId);
Assert.Equal("Completed", statusMessage.Status);
Assert.Equal(completedMessage.StartTime, statusMessage.StartTime);
Assert.Equal(completedMessage.EndTime, statusMessage.EndTime);
Assert.Same(completedMessage.Failure, statusMessage.Failure);
Assert.Same(completedMessage.OutputBlob, statusMessage.OutputBlob);
Assert.Same(completedMessage.ParameterLogBlob, statusMessage.ParameterLogBlob);
completedMessage.Failure = new FunctionFailure();
statusMessage = FunctionStatusLogger.CreateFunctionStatusMessage(completedMessage);
Assert.Same(completedMessage.Failure, statusMessage.Failure);
}
public async Task LogFunctionCompletedAsync_CallsTraceWriter()
{
FunctionDescriptor descriptor = new FunctionDescriptor
{
ShortName = "TestJob"
};
FunctionCompletedMessage successMessage = new FunctionCompletedMessage
{
Function = descriptor
};
Exception ex = new Exception("Kaboom!");
FunctionCompletedMessage failureMessage = new FunctionCompletedMessage
{
Function = descriptor,
Failure = new FunctionFailure {
Exception = ex
},
FunctionInstanceId = new Guid("8d71c9e3-e809-4cfb-bb78-48ae25c7d26d")
};
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Info, Host.TraceSource.Execution, "Executed: 'TestJob' (Succeeded)", null));
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Error, Host.TraceSource.Execution, "Executed: 'TestJob' (Failed)", ex));
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Error, Host.TraceSource.Host, " Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '8d71c9e3-e809-4cfb-bb78-48ae25c7d26d'", null));
await _logger.LogFunctionCompletedAsync(successMessage, CancellationToken.None);
await _logger.LogFunctionCompletedAsync(failureMessage, CancellationToken.None);
_mockTraceWriter.VerifyAll();
}
public async Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
foreach (IFunctionInstanceLogger logger in _loggers)
{
await logger.LogFunctionCompletedAsync(message, cancellationToken);
}
}
private void Process(PersistentQueueMessage message)
{
HostStartedMessage hostStartedMessage = message as HostStartedMessage;
if (hostStartedMessage != null)
{
_hostIndexer.ProcessHostStarted(hostStartedMessage);
return;
}
FunctionCompletedMessage functionCompletedMessage = message as FunctionCompletedMessage;
if (functionCompletedMessage != null)
{
_functionIndexer.ProcessFunctionCompleted(functionCompletedMessage);
return;
}
FunctionStartedMessage functionStartedMessage = message as FunctionStartedMessage;
if (functionStartedMessage != null)
{
_functionIndexer.ProcessFunctionStarted(functionStartedMessage);
return;
}
string errorMessage =
String.Format(CultureInfo.InvariantCulture, "Unknown message type '{0}'.", message.Type);
throw new InvalidOperationException(errorMessage);
}
public async Task LogFunctionCompletedAsync_CallsTraceWriter()
{
FunctionDescriptor descriptor = new FunctionDescriptor
{
ShortName = "TestJob"
};
FunctionCompletedMessage successMessage = new FunctionCompletedMessage
{
Function = descriptor
};
Exception ex = new Exception("Kaboom!");
FunctionCompletedMessage failureMessage = new FunctionCompletedMessage
{
Function = descriptor,
Failure = new FunctionFailure { Exception = ex },
FunctionInstanceId = new Guid("8d71c9e3-e809-4cfb-bb78-48ae25c7d26d")
};
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Info, Host.TraceSource.Execution, "Executed: 'TestJob' (Succeeded)", null));
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Error, Host.TraceSource.Execution, "Executed: 'TestJob' (Failed)", ex));
_mockTraceWriter.Setup(p => p.Trace(TraceLevel.Error, Host.TraceSource.Host, " Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '8d71c9e3-e809-4cfb-bb78-48ae25c7d26d'", null));
await _logger.LogFunctionCompletedAsync(successMessage, CancellationToken.None);
await _logger.LogFunctionCompletedAsync(failureMessage, CancellationToken.None);
_mockTraceWriter.VerifyAll();
}
public async Task LogFunctionCompletedAsync_CallsTraceWriter()
{
FunctionDescriptor descriptor = new FunctionDescriptor
{
ShortName = "TestJob",
FullName = "TestNamespace.TestJob"
};
FunctionCompletedMessage successMessage = new FunctionCompletedMessage
{
Function = descriptor,
FunctionInstanceId = Guid.NewGuid(),
HostInstanceId = Guid.NewGuid()
};
Exception ex = new Exception("Kaboom!");
FunctionCompletedMessage failureMessage = new FunctionCompletedMessage
{
Function = descriptor,
Failure = new FunctionFailure {
Exception = ex
},
FunctionInstanceId = new Guid("8d71c9e3-e809-4cfb-bb78-48ae25c7d26d"),
HostInstanceId = Guid.NewGuid()
};
await _logger.LogFunctionCompletedAsync(successMessage, CancellationToken.None);
await _logger.LogFunctionCompletedAsync(failureMessage, CancellationToken.None);
Assert.Equal(3, _traceWriter.Traces.Count);
TraceEvent traceEvent = _traceWriter.Traces[0];
Assert.Equal(TraceLevel.Info, traceEvent.Level);
Assert.Equal(Host.TraceSource.Execution, traceEvent.Source);
Assert.Equal(string.Format("Executed 'TestJob' (Succeeded, Id={0})", successMessage.FunctionInstanceId), traceEvent.Message);
Assert.Equal(successMessage.HostInstanceId, traceEvent.Properties["MS_HostInstanceId"]);
Assert.Equal(successMessage.FunctionInstanceId, traceEvent.Properties["MS_FunctionInvocationId"]);
Assert.Same(successMessage.Function, traceEvent.Properties["MS_FunctionDescriptor"]);
traceEvent = _traceWriter.Traces[1];
Assert.Equal(TraceLevel.Error, traceEvent.Level);
Assert.Equal(Host.TraceSource.Execution, traceEvent.Source);
Assert.Equal(string.Format("Executed 'TestJob' (Failed, Id={0})", failureMessage.FunctionInstanceId), traceEvent.Message);
Assert.Same(ex, traceEvent.Exception);
Assert.Equal(failureMessage.HostInstanceId, traceEvent.Properties["MS_HostInstanceId"]);
Assert.Equal(failureMessage.FunctionInstanceId, traceEvent.Properties["MS_FunctionInvocationId"]);
Assert.Same(failureMessage.Function, traceEvent.Properties["MS_FunctionDescriptor"]);
traceEvent = _traceWriter.Traces[2];
Assert.Equal(TraceLevel.Error, traceEvent.Level);
Assert.Equal(Host.TraceSource.Host, traceEvent.Source);
Assert.Equal(" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '8d71c9e3-e809-4cfb-bb78-48ae25c7d26d'", traceEvent.Message);
Assert.Same(ex, traceEvent.Exception);
Assert.Equal(failureMessage.HostInstanceId, traceEvent.Properties["MS_HostInstanceId"]);
Assert.Equal(failureMessage.FunctionInstanceId, traceEvent.Properties["MS_FunctionInvocationId"]);
Assert.Same(failureMessage.Function, traceEvent.Properties["MS_FunctionDescriptor"]);
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
return _queueWriter.EnqueueAsync(message, cancellationToken);
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
return(_queueWriter.EnqueueAsync(message, cancellationToken));
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null && message.Failure != null && message.Function != null &&
!_ignoreFailureFunctions.Contains(message.Function.FullName))
{
_taskSource.SetException(message.Failure.Exception);
}
return(Task.FromResult(0));
}
private static FunctionInstanceSnapshot CreateSnapshot(FunctionCompletedMessage message)
{
FunctionInstanceSnapshot entity = CreateSnapshot((FunctionStartedMessage)message);
entity.ParameterLogs = message.ParameterLogs;
entity.EndTime = message.EndTime;
entity.Succeeded = message.Succeeded;
entity.ExceptionType = message.Failure != null ? message.Failure.ExceptionType : null;
entity.ExceptionMessage = message.Failure != null ? message.Failure.ExceptionDetails : null;
return(entity);
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null)
{
// This class is used when a function is expected to fail (the result of the task is the expected
// exception).
// A faulted task is reserved for unexpected failures (like unhandled background exceptions).
_taskSource.SetResult(message.Failure != null ? message.Failure.Exception : null);
}
return Task.FromResult(0);
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null)
{
// This class is used when a function is expected to fail (the result of the task is the expected
// exception).
// A faulted task is reserved for unexpected failures (like unhandled background exceptions).
_taskSource.SetResult(message.Failure != null ? message.Failure.Exception : null);
}
return(Task.FromResult(0));
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (!message.Succeeded)
{
var oldColor = Console.ForegroundColor;
Console.ForegroundColor = ConsoleColor.Red;
Console.WriteLine(" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '{0}'",
message.FunctionInstanceId);
Console.ForegroundColor = oldColor;
}
return Task.FromResult(0);
}
public async Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
if (message.LogLevel == TraceLevel.Verbose)
{
FunctionStatusMessage statusMessage = CreateFunctionStatusMessage(message);
await LogFunctionStatusAsync(statusMessage, cancellationToken);
}
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (!message.Succeeded)
{
var oldColor = Console.ForegroundColor;
Console.ForegroundColor = ConsoleColor.Red;
Console.WriteLine(" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '{0}'",
message.FunctionInstanceId);
Console.ForegroundColor = oldColor;
}
return(Task.FromResult(0));
}
public async Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
if (message.Reason == ExecutionReason.Portal)
{
FunctionStatusMessage statusMessage = CreateFunctionStatusMessage(message);
await LogFunctionStatusAsync(statusMessage, cancellationToken);
}
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null && message.Failure != null)
{
_taskSource.SetException(message.Failure.Exception);
}
else
{
_taskSource.SetResult(null);
}
return(Task.FromResult(0));
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null && message.Failure != null)
{
_taskSource.SetException(message.Failure.Exception);
}
else
{
_taskSource.SetResult(null);
}
return Task.FromResult(0);
}
internal static FunctionStatusMessage CreateFunctionStatusMessage(FunctionCompletedMessage message)
{
return new FunctionStatusMessage()
{
FunctionId = message.Function.Id,
FunctionInstanceId = message.FunctionInstanceId,
Status = "Completed",
StartTime = message.StartTime,
EndTime = message.EndTime,
Failure = message.Failure,
OutputBlob = message.OutputBlob,
ParameterLogBlob = message.ParameterLogBlob
};
}
public async Task LogFunctionCompleted_CallsLogger()
{
FunctionDescriptor descriptor = new FunctionDescriptor
{
ShortName = "Function.TestJob",
LogName = "TestJob"
};
FunctionCompletedMessage successMessage = new FunctionCompletedMessage
{
Function = descriptor,
FunctionInstanceId = Guid.NewGuid(),
HostInstanceId = Guid.NewGuid()
};
Exception ex = new Exception("Kaboom!");
FunctionCompletedMessage failureMessage = new FunctionCompletedMessage
{
Function = descriptor,
Failure = new FunctionFailure {
Exception = ex
},
FunctionInstanceId = new Guid("8d71c9e3-e809-4cfb-bb78-48ae25c7d26d"),
HostInstanceId = Guid.NewGuid()
};
await _instanceLogger.LogFunctionCompletedAsync(successMessage, CancellationToken.None);
await _instanceLogger.LogFunctionCompletedAsync(failureMessage, CancellationToken.None);
LogMessage[] logMessages = _provider.GetAllLogMessages().ToArray();
Assert.Equal(2, logMessages.Length);
string expectedCategory = LogCategories.CreateFunctionCategory("TestJob");
LogMessage logMessage = logMessages[0];
Assert.Equal(LogLevel.Information, logMessage.Level);
Assert.Equal(expectedCategory, logMessage.Category);
Assert.Equal($"Executed 'Function.TestJob' (Succeeded, Id={successMessage.FunctionInstanceId})",
logMessage.FormattedMessage);
Assert.Null(logMessage.State);
logMessage = logMessages[1];
Assert.Equal(LogLevel.Error, logMessage.Level);
Assert.Equal(expectedCategory, logMessage.Category);
Assert.Equal($"Executed 'Function.TestJob' (Failed, Id={failureMessage.FunctionInstanceId})", logMessage.FormattedMessage);
Assert.Same(ex, logMessage.Exception);
Assert.Null(logMessage.State);
}
private async Task ProcessCallAndOverrideMessage(CallAndOverrideMessage message, CancellationToken cancellationToken)
{
IFunctionInstance instance = CreateFunctionInstance(message);
if (instance != null)
{
await _innerExecutor.TryExecuteAsync(instance, cancellationToken);
}
else
{
// Log that the function failed.
FunctionCompletedMessage failedMessage = CreateFailedMessage(message);
await _functionInstanceLogger.LogFunctionCompletedAsync(failedMessage, cancellationToken);
}
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message.Succeeded)
{
string traceMessage = string.Format(CultureInfo.InvariantCulture, "Executed '{0}' (Succeeded, Id={1})", message.Function.ShortName, message.FunctionInstanceId);
Log(LogLevel.Information, message.Function, message.FunctionInstanceId, traceMessage);
}
else
{
string traceMessage = string.Format(CultureInfo.InvariantCulture, "Executed '{0}' (Failed, Id={1})", message.Function.ShortName, message.FunctionInstanceId);
Log(LogLevel.Error, message.Function, message.FunctionInstanceId, traceMessage, message.Failure.Exception);
}
return(Task.CompletedTask);
}
Task IFunctionInstanceLogger.LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message != null && message.Failure != null && message.Function != null &&
!_ignoreFailureFunctions.Contains(message.Function.FullName))
{
_taskSource.SetException(message.Failure.Exception);
}
if (_signalOnFirst)
{
_taskSource.SetResult(default(TResult));
}
return(Task.CompletedTask);
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message.Succeeded)
{
_trace.Info(string.Format(CultureInfo.InvariantCulture, "Executed: '{0}' (Succeeded)", message.Function.ShortName), source: TraceSource.Execution);
}
else
{
_trace.Error(string.Format(CultureInfo.InvariantCulture, "Executed: '{0}' (Failed)", message.Function.ShortName), message.Failure.Exception, TraceSource.Execution);
// Also log the eror message using TraceSource.Host, to ensure
// it gets written to Console
_trace.Error(string.Format(CultureInfo.InvariantCulture,
" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '{0}'", message.FunctionInstanceId), message.Failure.Exception, TraceSource.Host);
}
return(Task.FromResult(0));
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
if (message.Succeeded)
{
_trace.Info(string.Format(CultureInfo.InvariantCulture, "Executed: '{0}' (Succeeded)", message.Function.ShortName), source: TraceSource.Execution);
}
else
{
_trace.Error(string.Format(CultureInfo.InvariantCulture, "Executed: '{0}' (Failed)", message.Function.ShortName), message.Failure.Exception, TraceSource.Execution);
// Also log the eror message using TraceSource.Host, to ensure
// it gets written to Console
_trace.Error(string.Format(CultureInfo.InvariantCulture,
" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '{0}'", message.FunctionInstanceId), message.Failure.Exception, TraceSource.Host);
}
return Task.FromResult(0);
}
// This method runs concurrently with other index processing.
// Ensure all logic here is idempotent.
public void ProcessFunctionCompleted(FunctionCompletedMessage message)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
FunctionInstanceSnapshot snapshot = CreateSnapshot(message);
// The completed message includes the full parameter logs; delete the extra blob used for running status
// updates.
DeleteParameterLogBlob(snapshot.ParameterLogBlob);
snapshot.ParameterLogBlob = null;
_functionInstanceLogger.LogFunctionCompleted(snapshot);
Guid functionInstanceId = message.FunctionInstanceId;
DateTimeOffset endTime = message.EndTime;
string functionId = new FunctionIdentifier(message.SharedQueueName, message.Function.Id).ToString();
Guid? parentId = message.ParentId;
WebJobRunIdentifier webJobRunId = message.WebJobRunIdentifier;
DeleteFunctionStartedIndexEntriesIfNeeded(functionInstanceId, message.StartTime, endTime, functionId,
parentId, webJobRunId);
CreateOrUpdateIndexEntries(snapshot, endTime, webJobRunId);
// Increment is non-idempotent. If the process dies before deleting the message that triggered it, it can
// occur multiple times.
// If we wanted to make this operation idempotent, one option would be to store the list of function
// instance IDs that succeeded & failed, rather than just the counters, so duplicate operations could be
// detected.
// For now, we just do a non-idempotent increment last, which makes it very unlikely that the queue message
// would not subsequently get deleted.
if (message.Succeeded)
{
_statisticsWriter.IncrementSuccess(functionId);
}
else
{
_statisticsWriter.IncrementFailure(functionId);
}
}
public async Task LogFunctionCompletedAsync_CallsTraceWriter()
{
FunctionDescriptor descriptor = new FunctionDescriptor
{
ShortName = "TestJob",
FullName = "TestNamespace.TestJob"
};
FunctionCompletedMessage successMessage = new FunctionCompletedMessage
{
Function = descriptor,
FunctionInstanceId = Guid.NewGuid()
};
Exception ex = new Exception("Kaboom!");
FunctionCompletedMessage failureMessage = new FunctionCompletedMessage
{
Function = descriptor,
Failure = new FunctionFailure { Exception = ex },
FunctionInstanceId = new Guid("8d71c9e3-e809-4cfb-bb78-48ae25c7d26d")
};
await _logger.LogFunctionCompletedAsync(successMessage, CancellationToken.None);
await _logger.LogFunctionCompletedAsync(failureMessage, CancellationToken.None);
Assert.Equal(3, _traceWriter.Traces.Count);
TraceEvent traceEvent = _traceWriter.Traces[0];
Assert.Equal(TraceLevel.Info, traceEvent.Level);
Assert.Equal(Host.TraceSource.Execution, traceEvent.Source);
Assert.Equal("Executed: 'TestJob' (Succeeded)", traceEvent.Message);
traceEvent = _traceWriter.Traces[1];
Assert.Equal(TraceLevel.Error, traceEvent.Level);
Assert.Equal(Host.TraceSource.Execution, traceEvent.Source);
Assert.Equal("Executed: 'TestJob' (Failed)", traceEvent.Message);
Assert.Same(ex, traceEvent.Exception);
traceEvent = _traceWriter.Traces[2];
Assert.Equal(TraceLevel.Error, traceEvent.Level);
Assert.Equal(Host.TraceSource.Host, traceEvent.Source);
Assert.Equal(" Function had errors. See Azure WebJobs SDK dashboard for details. Instance ID is '8d71c9e3-e809-4cfb-bb78-48ae25c7d26d'", traceEvent.Message);
Assert.Same(ex, traceEvent.Exception);
}
private static FunctionInstanceSnapshot CreateSnapshot(FunctionCompletedMessage message)
{
FunctionInstanceSnapshot entity = CreateSnapshot((FunctionStartedMessage)message);
entity.ParameterLogs = message.ParameterLogs;
entity.EndTime = message.EndTime;
entity.Succeeded = message.Succeeded;
entity.ExceptionType = message.Failure != null ? message.Failure.ExceptionType : null;
entity.ExceptionMessage = message.Failure != null ? message.Failure.ExceptionDetails : null;
return entity;
}
Task IFunctionInstanceLogger.LogFunctionCompletedAsync(FunctionCompletedMessage message,
CancellationToken cancellationToken)
{
return Task.FromResult(0);
}
// This method runs concurrently with other index processing.
// Ensure all logic here is idempotent.
public void ProcessFunctionCompleted(FunctionCompletedMessage message)
{
if (message == null)
{
throw new ArgumentNullException("message");
}
FunctionInstanceSnapshot snapshot = CreateSnapshot(message);
// The completed message includes the full parameter logs; delete the extra blob used for running status
// updates.
DeleteParameterLogBlob(snapshot.ParameterLogBlob);
snapshot.ParameterLogBlob = null;
_functionInstanceLogger.LogFunctionCompleted(snapshot);
Guid functionInstanceId = message.FunctionInstanceId;
DateTimeOffset endTime = message.EndTime;
string functionId = new FunctionIdentifier(message.SharedQueueName, message.Function.Id).ToString();
Guid? parentId = message.ParentId;
WebJobRunIdentifier webJobRunId = message.WebJobRunIdentifier;
DeleteFunctionStartedIndexEntriesIfNeeded(functionInstanceId, message.StartTime, endTime, functionId,
parentId, webJobRunId);
CreateOrUpdateIndexEntries(snapshot, endTime, webJobRunId);
// Increment is non-idempotent. If the process dies before deleting the message that triggered it, it can
// occur multiple times.
// If we wanted to make this operation idempotent, one option would be to store the list of function
// instance IDs that succeeded & failed, rather than just the counters, so duplicate operations could be
// detected.
// For now, we just do a non-idempotent increment last, which makes it very unlikely that the queue message
// would not subsequently get deleted.
if (message.Succeeded)
{
_statisticsWriter.IncrementSuccess(functionId);
}
else
{
_statisticsWriter.IncrementFailure(functionId);
}
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
return Task.FromResult(0);
}
public async Task <IDelayedException> TryExecuteAsync(IFunctionInstance functionInstance, CancellationToken cancellationToken)
{
FunctionStartedMessage functionStartedMessage = CreateStartedMessageWithoutArguments(functionInstance);
IDictionary <string, ParameterLog> parameterLogCollector = new Dictionary <string, ParameterLog>();
FunctionCompletedMessage functionCompletedMessage = null;
ExceptionDispatchInfo exceptionInfo = null;
string functionStartedMessageId = null;
TraceLevel functionTraceLevel = GetFunctionTraceLevel(functionInstance);
FunctionInstanceLogEntry fastItem = new FunctionInstanceLogEntry
{
FunctionInstanceId = functionStartedMessage.FunctionInstanceId,
ParentId = functionStartedMessage.ParentId,
FunctionName = functionStartedMessage.Function.ShortName,
TriggerReason = functionStartedMessage.ReasonDetails,
StartTime = functionStartedMessage.StartTime.DateTime
};
try
{
functionStartedMessageId = await ExecuteWithLoggingAsync(functionInstance, functionStartedMessage, fastItem, parameterLogCollector, functionTraceLevel, cancellationToken);
functionCompletedMessage = CreateCompletedMessage(functionStartedMessage);
}
catch (Exception exception)
{
if (functionCompletedMessage == null)
{
functionCompletedMessage = CreateCompletedMessage(functionStartedMessage);
}
functionCompletedMessage.Failure = new FunctionFailure
{
Exception = exception,
ExceptionType = exception.GetType().FullName,
ExceptionDetails = exception.ToDetails(),
};
exceptionInfo = ExceptionDispatchInfo.Capture(exception);
}
if (functionCompletedMessage != null)
{
functionCompletedMessage.ParameterLogs = parameterLogCollector;
functionCompletedMessage.EndTime = DateTimeOffset.UtcNow;
}
bool loggedStartedEvent = functionStartedMessageId != null;
CancellationToken logCompletedCancellationToken;
if (loggedStartedEvent)
{
// If function started was logged, don't cancel calls to log function completed.
logCompletedCancellationToken = CancellationToken.None;
}
else
{
logCompletedCancellationToken = cancellationToken;
}
if (_fastLogger != null)
{
// Log completed
fastItem.EndTime = DateTime.UtcNow;
fastItem.Arguments = functionCompletedMessage.Arguments;
if (exceptionInfo != null)
{
var ex = exceptionInfo.SourceException;
if (ex.InnerException != null)
{
ex = ex.InnerException;
}
fastItem.ErrorDetails = ex.Message;
}
await _fastLogger.AddAsync(fastItem);
}
if (functionCompletedMessage != null &&
((functionTraceLevel >= TraceLevel.Info) || (functionCompletedMessage.Failure != null && functionTraceLevel >= TraceLevel.Error)))
{
await _functionInstanceLogger.LogFunctionCompletedAsync(functionCompletedMessage, logCompletedCancellationToken);
}
if (loggedStartedEvent)
{
await _functionInstanceLogger.DeleteLogFunctionStartedAsync(functionStartedMessageId, cancellationToken);
}
if (exceptionInfo != null)
{
await HandleExceptionAsync(functionInstance.FunctionDescriptor.Method, exceptionInfo, _exceptionHandler);
}
return(exceptionInfo != null ? new ExceptionDispatchInfoDelayedException(exceptionInfo) : null);
}
public async Task <IDelayedException> TryExecuteAsync(IFunctionInstance functionInstance, CancellationToken cancellationToken)
{
FunctionStartedMessage functionStartedMessage = CreateStartedMessageWithoutArguments(functionInstance);
IDictionary <string, ParameterLog> parameterLogCollector = new Dictionary <string, ParameterLog>();
FunctionCompletedMessage functionCompletedMessage = null;
ExceptionDispatchInfo exceptionInfo = null;
string functionStartedMessageId = null;
TraceLevel functionTraceLevel = GetFunctionTraceLevel(functionInstance);
try
{
functionStartedMessageId = await ExecuteWithLoggingAsync(functionInstance, functionStartedMessage, parameterLogCollector, functionTraceLevel, cancellationToken);
functionCompletedMessage = CreateCompletedMessage(functionStartedMessage);
}
catch (Exception exception)
{
if (functionCompletedMessage == null)
{
functionCompletedMessage = CreateCompletedMessage(functionStartedMessage);
}
functionCompletedMessage.Failure = new FunctionFailure
{
Exception = exception,
ExceptionType = exception.GetType().FullName,
ExceptionDetails = exception.ToDetails(),
};
exceptionInfo = ExceptionDispatchInfo.Capture(exception);
}
if (functionCompletedMessage != null)
{
functionCompletedMessage.ParameterLogs = parameterLogCollector;
functionCompletedMessage.EndTime = DateTimeOffset.UtcNow;
}
bool loggedStartedEvent = functionStartedMessageId != null;
CancellationToken logCompletedCancellationToken;
if (loggedStartedEvent)
{
// If function started was logged, don't cancel calls to log function completed.
logCompletedCancellationToken = CancellationToken.None;
}
else
{
logCompletedCancellationToken = cancellationToken;
}
if (functionCompletedMessage != null &&
((functionTraceLevel >= TraceLevel.Info) || (functionCompletedMessage.Failure != null && functionTraceLevel >= TraceLevel.Error)))
{
await _functionInstanceLogger.LogFunctionCompletedAsync(functionCompletedMessage, logCompletedCancellationToken);
}
if (loggedStartedEvent)
{
await _functionInstanceLogger.DeleteLogFunctionStartedAsync(functionStartedMessageId, cancellationToken);
}
return(exceptionInfo != null ? new ExceptionDispatchInfoDelayedException(exceptionInfo) : null);
}
public async Task LogFunctionCompletedAsync_NonPortal_DoesNotWriteBlob()
{
FunctionCompletedMessage completedMessage = new FunctionCompletedMessage
{
Reason = ExecutionReason.Dashboard
};
// Since we haven't set up the mocks, this would throw if it didn't noop
await _logger.LogFunctionCompletedAsync(completedMessage, CancellationToken.None);
}
public async Task LogFunctionCompletedAsync_Portal_WritesExpectedBlob()
{
FunctionCompletedMessage completedMessage = new FunctionCompletedMessage
{
Function = new FunctionDescriptor
{
Id = "TestHost.TestFunction"
},
FunctionInstanceId = Guid.NewGuid(),
StartTime = DateTime.Now,
EndTime = DateTime.Now,
OutputBlob = new LocalBlobDescriptor(),
ParameterLogBlob = new LocalBlobDescriptor(),
Reason = ExecutionReason.Portal
};
FunctionStatusMessage statusMessage = FunctionStatusLogger.CreateFunctionStatusMessage(completedMessage);
CancellationToken cancellationToken = new CancellationToken();
string expectedContent = JsonConvert.SerializeObject(statusMessage, JsonSerialization.Settings);
string blobName = string.Format("invocations/{0}/{1}/{2}", _hostId, completedMessage.Function.Id, completedMessage.FunctionInstanceId);
Mock<IStorageBlockBlob> blobMock = new Mock<IStorageBlockBlob>(MockBehavior.Strict);
blobMock.Setup(p => p.UploadTextAsync(expectedContent, null, null, null, null, cancellationToken)).Returns(Task.FromResult(0));
_containerMock.Setup(p => p.GetBlockBlobReference(blobName)).Returns(blobMock.Object);
await _logger.LogFunctionCompletedAsync(completedMessage, cancellationToken);
_containerMock.VerifyAll();
blobMock.VerifyAll();
}
Task IFunctionInstanceLogger.LogFunctionCompletedAsync(FunctionCompletedMessage message,
CancellationToken cancellationToken)
{
return(Task.FromResult(0));
}
public Task LogFunctionCompletedAsync(FunctionCompletedMessage message, CancellationToken cancellationToken)
{
return(Task.FromResult(0));
}
