public void Decorator_BeginEventWithParams_Called()
{
string eventName = "blah";
string functionName = "blah";
string data = "moreBlah";
_metricsLogger.Setup(a => a.BeginEvent(eventName, functionName, data));
_metricsLoggerDecorator.BeginEvent(eventName, functionName, data);
_metricsLogger.Verify(a => a.BeginEvent(eventName, functionName, data), Times.Once());
_metricsLogger.Reset();
}
private void StartFunction(FunctionInstanceLogEntry item)
{
if (_metadataManager.TryGetFunctionMetadata(item.LogName, out FunctionMetadata function))
{
var startedEvent = new FunctionStartedEvent(item.FunctionInstanceId, function);
_metrics.BeginEvent(startedEvent);
var invokeLatencyEvent = LogInvocationMetrics(function);
item.Properties[Key] = (startedEvent, invokeLatencyEvent);
}
else
{
throw new InvalidOperationException($"Unable to load metadata for function '{item.LogName}'.");
}
}
public void Start()
{
startedEvent = new FunctionStartedEvent(_invocationId, _metadata);
_metrics.BeginEvent(startedEvent);
invokeLatencyEvent = FunctionInvokerBase.LogInvocationMetrics(_metrics, _metadata);
_invocationStopWatch.Start();
}
public override async Task Invoke(object[] parameters)
{
// TODO: Refactor common code for providers.
object input = parameters[0];
TraceWriter traceWriter = (TraceWriter)parameters[1];
Binder binder = (Binder)parameters[2];
ExecutionContext functionExecutionContext = (ExecutionContext)parameters[3];
string invocationId = functionExecutionContext.InvocationId.ToString();
FunctionStartedEvent startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
try
{
TraceWriter.Info(string.Format("Function started (Id={0})", invocationId));
object convertedInput = ConvertInput(input);
ApplyBindingData(convertedInput, binder);
Dictionary <string, object> bindingData = binder.BindingData;
bindingData["InvocationId"] = invocationId;
Dictionary <string, string> environmentVariables = new Dictionary <string, string>();
string functionInstanceOutputPath = Path.Combine(Path.GetTempPath(), "Functions", "Binding", invocationId);
await ProcessInputBindingsAsync(convertedInput, functionInstanceOutputPath, binder, _inputBindings, _outputBindings, bindingData, environmentVariables);
InitializeEnvironmentVariables(environmentVariables, functionInstanceOutputPath, input, _outputBindings, functionExecutionContext);
PSDataCollection <ErrorRecord> errors = await InvokePowerShellScript(environmentVariables, traceWriter);
await ProcessOutputBindingsAsync(functionInstanceOutputPath, _outputBindings, input, binder, bindingData);
if (errors.Any())
{
ErrorRecord error = errors.FirstOrDefault();
if (error != null)
{
throw new RuntimeException("PowerShell script error", error.Exception, error);
}
}
else
{
TraceWriter.Info(string.Format("Function completed (Success, Id={0})", invocationId));
}
}
catch (Exception)
{
startedEvent.Success = false;
TraceWriter.Error(string.Format("Function completed (Failure, Id={0})", invocationId));
throw;
}
finally
{
_metrics.EndEvent(startedEvent);
}
}
internal static object LogInvocationMetrics(IMetricsLogger metrics, FunctionMetadata metadata)
{
// log events for each of the binding types used
foreach (var binding in metadata.Bindings)
{
string eventName = binding.IsTrigger ?
string.Format(MetricEventNames.FunctionBindingTypeFormat, binding.Type) :
string.Format(MetricEventNames.FunctionBindingTypeDirectionFormat, binding.Type, binding.Direction);
metrics.LogEvent(eventName);
}
return(metrics.BeginEvent(MetricEventNames.FunctionInvokeLatency, metadata.Name));
}
public override async Task Invoke(object[] parameters)
{
object input = parameters[0];
TraceWriter traceWriter = (TraceWriter)parameters[1];
IBinderEx binder = (IBinderEx)parameters[2];
ExecutionContext functionExecutionContext = (ExecutionContext)parameters[3];
string invocationId = functionExecutionContext.InvocationId.ToString();
FunctionStartedEvent startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
try
{
TraceWriter.Verbose(string.Format("Function started (Id={0})", invocationId));
var scriptExecutionContext = CreateScriptExecutionContext(input, traceWriter, TraceWriter, functionExecutionContext);
Dictionary <string, string> bindingData = GetBindingData(input, binder, _inputBindings, _outputBindings);
bindingData["InvocationId"] = invocationId;
scriptExecutionContext["bindingData"] = bindingData;
await ProcessInputBindingsAsync(binder, scriptExecutionContext, bindingData);
object functionResult = await ScriptFunc(scriptExecutionContext);
await ProcessOutputBindingsAsync(_outputBindings, input, binder, bindingData, scriptExecutionContext, functionResult);
TraceWriter.Verbose(string.Format("Function completed (Success, Id={0})", invocationId));
}
catch
{
startedEvent.Success = false;
TraceWriter.Verbose(string.Format("Function completed (Failure, Id={0})", invocationId));
throw;
}
finally
{
_metrics.EndEvent(startedEvent);
}
}
public DisposableEvent(string eventName, string functionName, IMetricsLogger metricsLogger)
{
_metricEvent = metricsLogger.BeginEvent(eventName, functionName);
_metricsLogger = metricsLogger;
}
public async Task Invoke(object[] parameters)
{
// We require the ExecutionContext, so this will throw if one is not found.
ExecutionContext functionExecutionContext = parameters.OfType <ExecutionContext>().First();
PopulateExecutionContext(functionExecutionContext);
// These may not be present, so null is okay.
TraceWriter functionTraceWriter = parameters.OfType <TraceWriter>().FirstOrDefault();
Binder binder = parameters.OfType <Binder>().FirstOrDefault();
ILogger logger = parameters.OfType <ILogger>().FirstOrDefault();
string invocationId = functionExecutionContext.InvocationId.ToString();
var startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
var invokeLatencyEvent = LogInvocationMetrics(_metrics, Metadata);
var invocationStopWatch = new Stopwatch();
invocationStopWatch.Start();
try
{
string startMessage = $"Function started (Id={invocationId})";
TraceWriter.Info(startMessage);
Logger?.LogInformation(startMessage);
FunctionInvocationContext context = new FunctionInvocationContext
{
ExecutionContext = functionExecutionContext,
Binder = binder,
TraceWriter = functionTraceWriter,
Logger = logger
};
await InvokeCore(parameters, context);
invocationStopWatch.Stop();
LogFunctionResult(startedEvent, true, invocationId, invocationStopWatch.ElapsedMilliseconds);
}
catch (AggregateException ex)
{
ExceptionDispatchInfo exInfo = null;
// If there's only a single exception, rethrow it by itself
Exception singleEx = ex.Flatten().InnerExceptions.SingleOrDefault();
if (singleEx != null)
{
exInfo = ExceptionDispatchInfo.Capture(singleEx);
}
else
{
exInfo = ExceptionDispatchInfo.Capture(ex);
}
invocationStopWatch.Stop();
LogFunctionResult(startedEvent, false, invocationId, invocationStopWatch.ElapsedMilliseconds);
exInfo.Throw();
}
catch
{
invocationStopWatch.Stop();
LogFunctionResult(startedEvent, false, invocationId, invocationStopWatch.ElapsedMilliseconds);
throw;
}
finally
{
if (startedEvent != null)
{
_metrics.EndEvent(startedEvent);
}
if (invokeLatencyEvent != null)
{
_metrics.EndEvent(invokeLatencyEvent);
}
}
}
public override async Task Invoke(object[] parameters)
{
FunctionStartedEvent startedEvent = null;
string invocationId = null;
try
{
// Separate system parameters from the actual method parameters
object[] originalParameters = parameters;
MethodInfo function = await GetFunctionTargetAsync();
int actualParameterCount = function.GetParameters().Length;
object[] systemParameters = parameters.Skip(actualParameterCount).ToArray();
parameters = parameters.Take(actualParameterCount).ToArray();
ExecutionContext functionExecutionContext = (ExecutionContext)systemParameters[0];
invocationId = functionExecutionContext.InvocationId.ToString();
startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
TraceWriter.Info(string.Format("Function started (Id={0})", invocationId));
parameters = ProcessInputParameters(parameters);
object functionResult = function.Invoke(null, parameters);
// after the function executes, we have to copy values back into the original
// array to ensure object references are maintained (since we took a copy above)
for (int i = 0; i < parameters.Length; i++)
{
originalParameters[i] = parameters[i];
}
if (functionResult is Task)
{
functionResult = await((Task)functionResult).ContinueWith(t => GetTaskResult(t));
}
if (functionResult != null)
{
_resultProcessor(function, parameters, systemParameters, functionResult);
}
TraceWriter.Info(string.Format("Function completed (Success, Id={0})", invocationId));
}
catch
{
if (startedEvent != null)
{
startedEvent.Success = false;
TraceWriter.Error(string.Format("Function completed (Failure, Id={0})", invocationId));
}
else
{
TraceWriter.Error("Function completed (Failure)");
}
throw;
}
finally
{
if (startedEvent != null)
{
_metrics.EndEvent(startedEvent);
}
}
}
public DisposableEvent(string eventName, string functionName, IMetricsLogger metricsLogger)
{
_metricEvent = metricsLogger.BeginEvent(eventName, functionName, $"{{\"IsStopwatchHighResolution:\" {Stopwatch.IsHighResolution}}}");
_metricsLogger = metricsLogger;
}
public async Task Invoke(object[] parameters)
{
// We require the ExecutionContext, so this will throw if one is not found.
ExecutionContext functionExecutionContext = parameters.OfType <ExecutionContext>().First();
// These may not be present, so null is okay.
TraceWriter functionTraceWriter = parameters.OfType <TraceWriter>().FirstOrDefault();
Binder binder = parameters.OfType <Binder>().FirstOrDefault();
string invocationId = functionExecutionContext.InvocationId.ToString();
FunctionStartedEvent startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
LogInvocationMetrics(_metrics, Metadata.Bindings);
try
{
TraceWriter.Info($"Function started (Id={invocationId})");
FunctionInvocationContext context = new FunctionInvocationContext
{
ExecutionContext = functionExecutionContext,
Binder = binder,
TraceWriter = functionTraceWriter
};
await InvokeCore(parameters, context);
TraceWriter.Info($"Function completed (Success, Id={invocationId})");
}
catch (AggregateException ex)
{
ExceptionDispatchInfo exInfo = null;
// If there's only a single exception, rethrow it by itself
Exception singleEx = ex.Flatten().InnerExceptions.SingleOrDefault();
if (singleEx != null)
{
exInfo = ExceptionDispatchInfo.Capture(singleEx);
}
else
{
exInfo = ExceptionDispatchInfo.Capture(ex);
}
LogFunctionFailed(startedEvent, "Failure", invocationId);
exInfo.Throw();
}
catch
{
LogFunctionFailed(startedEvent, "Failure", invocationId);
throw;
}
finally
{
if (startedEvent != null)
{
_metrics.EndEvent(startedEvent);
}
}
}
public DisposableEvent(string eventName, IMetricsLogger metricsLogger)
{
_metricEvent = metricsLogger.BeginEvent(eventName);
_metricsLogger = metricsLogger;
}
internal async Task ExecuteScriptAsync(string path, string arguments, object[] invocationParameters)
{
object input = invocationParameters[0];
TraceWriter traceWriter = (TraceWriter)invocationParameters[1];
IBinderEx binder = (IBinderEx)invocationParameters[2];
ExecutionContext functionExecutionContext = (ExecutionContext)invocationParameters[3];
string invocationId = functionExecutionContext.InvocationId.ToString();
FunctionStartedEvent startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
// perform any required input conversions
object convertedInput = input;
if (input != null)
{
HttpRequestMessage request = input as HttpRequestMessage;
if (request != null)
{
// TODO: Handle other content types? (E.g. byte[])
if (request.Content != null && request.Content.Headers.ContentLength > 0)
{
convertedInput = ((HttpRequestMessage)input).Content.ReadAsStringAsync().Result;
}
}
}
TraceWriter.Info(string.Format("Function started (Id={0})", invocationId));
string workingDirectory = Path.GetDirectoryName(_scriptFilePath);
string functionInstanceOutputPath = Path.Combine(Path.GetTempPath(), "Functions", "Binding", invocationId);
Dictionary <string, string> environmentVariables = new Dictionary <string, string>();
InitializeEnvironmentVariables(environmentVariables, functionInstanceOutputPath, input, _outputBindings, functionExecutionContext);
Dictionary <string, string> bindingData = GetBindingData(convertedInput, binder);
bindingData["InvocationId"] = invocationId;
await ProcessInputBindingsAsync(convertedInput, functionInstanceOutputPath, binder, bindingData, environmentVariables);
// TODO
// - put a timeout on how long we wait?
// - need to periodically flush the standard out to the TraceWriter
Process process = CreateProcess(path, workingDirectory, arguments, environmentVariables);
process.Start();
process.WaitForExit();
bool failed = process.ExitCode != 0;
startedEvent.Success = !failed;
_metrics.EndEvent(startedEvent);
if (failed)
{
startedEvent.Success = false;
TraceWriter.Error(string.Format("Function completed (Failure, Id={0})", invocationId));
string error = process.StandardError.ReadToEnd();
throw new ApplicationException(error);
}
string output = process.StandardOutput.ReadToEnd();
TraceWriter.Info(output);
traceWriter.Info(output);
await ProcessOutputBindingsAsync(functionInstanceOutputPath, _outputBindings, input, binder, bindingData);
TraceWriter.Info(string.Format("Function completed (Success, Id={0})", invocationId));
}
internal async Task ExecuteScriptAsync(string path, string arguments, object[] invocationParameters)
{
object input = invocationParameters[0];
TraceWriter traceWriter = (TraceWriter)invocationParameters[1];
Binder binder = (Binder)invocationParameters[2];
ExecutionContext functionExecutionContext = (ExecutionContext)invocationParameters[3];
string invocationId = functionExecutionContext.InvocationId.ToString();
FunctionStartedEvent startedEvent = new FunctionStartedEvent(functionExecutionContext.InvocationId, Metadata);
_metrics.BeginEvent(startedEvent);
try
{
TraceWriter.Info(string.Format("Function started (Id={0})", invocationId));
string workingDirectory = Path.GetDirectoryName(_scriptFilePath);
string functionInstanceOutputPath = Path.Combine(Path.GetTempPath(), "Functions", "Binding", invocationId);
Dictionary <string, string> environmentVariables = new Dictionary <string, string>();
InitializeEnvironmentVariables(environmentVariables, functionInstanceOutputPath, input, _outputBindings, functionExecutionContext);
object convertedInput = ConvertInput(input);
ApplyBindingData(convertedInput, binder);
Dictionary <string, object> bindingData = binder.BindingData;
bindingData["InvocationId"] = invocationId;
await ProcessInputBindingsAsync(convertedInput, functionInstanceOutputPath, binder, _inputBindings, _outputBindings, bindingData, environmentVariables);
// TODO
// - put a timeout on how long we wait?
// - need to periodically flush the standard out to the TraceWriter
Process process = CreateProcess(path, workingDirectory, arguments, environmentVariables);
process.Start();
process.WaitForExit();
string output = process.StandardOutput.ReadToEnd();
TraceWriter.Info(output);
traceWriter.Info(output);
startedEvent.Success = process.ExitCode == 0;
if (!startedEvent.Success)
{
string error = process.StandardError.ReadToEnd();
throw new ApplicationException(error);
}
await ProcessOutputBindingsAsync(functionInstanceOutputPath, _outputBindings, input, binder, bindingData);
TraceWriter.Info(string.Format("Function completed (Success, Id={0})", invocationId));
}
catch
{
startedEvent.Success = false;
TraceWriter.Error(string.Format("Function completed (Failure, Id={0})", invocationId));
throw;
}
finally
{
_metrics.EndEvent(startedEvent);
}
}
public DisposableEvent(string eventName, string functionName, IMetricsLogger metricsLogger)
{
_metricEvent = metricsLogger.BeginEvent(eventName, functionName, Stopwatch.IsHighResolution ? @"{""IsStopwatchHighResolution"": True}" : @"{""IsStopwatchHighResolution"": False}");
_metricsLogger = metricsLogger;
}
public object BeginEvent(string eventName, string functionName = null, string data = null)
{
return(_metricsLogger.BeginEvent(eventName, functionName, data));
}
