internal async Task ExecuteWithLoggingAsync()

in src/Microsoft.Azure.WebJobs.Host/Executors/FunctionExecutor.cs [261:368]


        internal async Task<string> ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message,
            FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken)
        {
            var outputDefinition = await _functionOutputLogger.CreateAsync(instance, cancellationToken);
            var outputLog = outputDefinition.CreateOutput();
            var updateOutputLogTimer = StartOutputTimer(outputLog.UpdateCommand, _exceptionHandler);

            try
            {
                // Create a linked token source that will allow us to signal function cancellation
                // (e.g. Based on TimeoutAttribute, etc.)                
                CancellationTokenSource functionCancellationTokenSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);

                using (functionCancellationTokenSource)
                {
                    FunctionOutputLogger.SetOutput(outputLog);

                    // Must bind before logging (bound invoke string is included in log message).
                    var functionContext = new FunctionBindingContext(instance, functionCancellationTokenSource.Token);
                    var valueBindingContext = new ValueBindingContext(functionContext, cancellationToken);

                    using (logger.BeginScope(_inputBindingScope))
                    {
                        var valueProviders = await instance.BindingSource.BindAsync(valueBindingContext);
                        parameterHelper.SetValueProviders(valueProviders);
                    }

                    // Log started events
                    CompleteStartedMessage(message, outputDefinition, parameterHelper);
                    string startedMessageId = _functionInstanceLogger.LogFunctionStarted(message);

                    instanceLogEntry.Arguments = message.Arguments;
                    await _functionEventCollector.AddAsync(instanceLogEntry);

                    Exception invocationException = null;
                    ITaskSeriesTimer updateParameterLogTimer = null;
                    try
                    {
                        if (outputDefinition != NullFunctionOutputDefinition.Instance)
                        {
                            var parameterWatchers = parameterHelper.CreateParameterWatchers();
                            var updateParameterLogCommand = outputDefinition.CreateParameterLogUpdateCommand(parameterWatchers, logger);
                            updateParameterLogTimer = StartParameterLogTimer(updateParameterLogCommand, _exceptionHandler);
                        }

                        await ExecuteWithWatchersAsync(instance, parameterHelper, logger, functionCancellationTokenSource);

                        if (updateParameterLogTimer != null)
                        {
                            // Stop the watches after calling IValueBinder.SetValue (it may do things that should show up in
                            // the watches).
                            // Also, IValueBinder.SetValue could also take a long time (flushing large caches), and so it's
                            // useful to have watches still running.
                            await updateParameterLogTimer.StopAsync(functionCancellationTokenSource.Token);
                        }
                    }
                    catch (Exception ex)
                    {
                        invocationException = ex;
                    }
                    finally
                    {
                        updateParameterLogTimer?.Dispose();
                        parameterHelper.FlushParameterWatchers();
                    }

                    var exceptionInfo = GetExceptionDispatchInfo(invocationException, instance);
                    if (exceptionInfo == null && updateOutputLogTimer != null)
                    {
                        await updateOutputLogTimer.StopAsync(cancellationToken);
                    }

                    // We save the exception info above rather than throwing to ensure we always write
                    // console output even if the function fails or was canceled.
                    if (outputLog != null)
                    {
                        await outputLog.SaveAndCloseAsync(instanceLogEntry, cancellationToken);
                    }

                    if (exceptionInfo != null)
                    {
                        if (parameterHelper.HasSingleton)
                        {
                            // release any held singleton lock immediately
                            SingletonLock singleton = await parameterHelper.GetSingletonLockAsync();
                            if (singleton != null && singleton.IsHeld)
                            {
                                await singleton.ReleaseAsync(CancellationToken.None);
                            }
                        }

                        exceptionInfo.Throw();
                    }
                    return startedMessageId;
                }
            }
            finally
            {
                if (outputLog != null)
                {
                    outputLog.Dispose();
                }
                if (updateOutputLogTimer != null)
                {
                    updateOutputLogTimer.Dispose();
                }
            }
        }