Skip to content

Commit e58cf9e

Browse files
brettsambrettsam
authored
improving handling and logging of exceptions thrown during external startup (#9091)
1 parent e72a467 commit e58cf9e

File tree

16 files changed

+254
-30
lines changed

16 files changed

+254
-30
lines changed

‎src/WebJobs.Script.WebHost/Diagnostics/DiagnosticEventLogger.cs‎

Lines changed: 28 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -6,31 +6,47 @@
66
using System.Linq;
77
using Microsoft.Azure.WebJobs.Script.Config;
88
using Microsoft.Extensions.Logging;
9+
using Microsoft.Extensions.Options;
910

1011
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
1112
{
12-
public class DiagnosticEventLogger : ILogger
13+
public class DiagnosticEventLogger : ILogger, IDisposable
1314
{
1415
private readonly IDiagnosticEventRepositoryFactory _diagnosticEventRepositoryFactory;
1516
private readonly IEnvironment _environment;
17+
private readonly IDisposable _standbyChangeHandler;
18+
1619
private IDiagnosticEventRepository _diagnosticEventRepository;
20+
private bool _isEnabled;
1721

18-
public DiagnosticEventLogger(IDiagnosticEventRepositoryFactory diagnosticEventRepositoryFactory, IEnvironment environment)
22+
public DiagnosticEventLogger(IDiagnosticEventRepositoryFactory diagnosticEventRepositoryFactory, IEnvironment environment,
23+
IOptionsMonitor<StandbyOptions> standbyOptions)
1924
{
2025
_diagnosticEventRepositoryFactory = diagnosticEventRepositoryFactory;
2126
_environment = environment;
27+
28+
SetEnabledState(standbyOptions.CurrentValue);
29+
30+
// Re-evaluate whether this is enabled after specialization
31+
if (standbyOptions.CurrentValue.InStandbyMode)
32+
{
33+
_standbyChangeHandler = standbyOptions.OnChange(o => SetEnabledState(o));
34+
}
2235
}
2336

24-
public IDisposable BeginScope<TState>(TState state)
37+
private void SetEnabledState(StandbyOptions options)
2538
{
26-
return null;
39+
_isEnabled = !options.InStandbyMode &&
40+
!FeatureFlags.IsEnabled(ScriptConstants.FeatureFlagDisableDiagnosticEventLogging, _environment);
2741
}
2842

29-
public bool IsEnabled(LogLevel logLevel)
43+
public IDisposable BeginScope<TState>(TState state)
3044
{
31-
return !_environment.IsPlaceholderModeEnabled();
45+
return null;
3246
}
3347

48+
public bool IsEnabled(LogLevel logLevel) => _isEnabled;
49+
3450
private bool IsDiagnosticEvent(IDictionary<string, object> state)
3551
{
3652
return state.Keys.Contains(ScriptConstants.DiagnosticEventKey, StringComparer.OrdinalIgnoreCase);
@@ -53,5 +69,11 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
5369
_diagnosticEventRepository.WriteDiagnosticEvent(DateTime.UtcNow, stateInfo[ScriptConstants.ErrorCodeKey].ToString(), logLevel, message, stateInfo[ScriptConstants.HelpLinkKey].ToString(), exception);
5470
}
5571
}
72+
73+
public void Dispose()
74+
{
75+
_standbyChangeHandler?.Dispose();
76+
(_diagnosticEventRepository as IDisposable)?.Dispose();
77+
}
5678
}
5779
}

‎src/WebJobs.Script.WebHost/Diagnostics/DiagnosticEventLoggerProvider.cs‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2,25 +2,28 @@
22
// Licensed under the MIT License. See License.txt in the project root for license information.
33

44
using System;
5-
using System.Threading.Tasks;
65
using Microsoft.Extensions.Logging;
6+
using Microsoft.Extensions.Options;
77

88
namespace Microsoft.Azure.WebJobs.Script.WebHost.Diagnostics
99
{
1010
public class DiagnosticEventLoggerProvider : ILoggerProvider
1111
{
1212
private readonly IDiagnosticEventRepositoryFactory _diagnosticEventRepositoryFactory;
1313
private readonly IEnvironment _environment;
14+
private readonly IOptionsMonitor<StandbyOptions> _standbyOptions;
1415

15-
public DiagnosticEventLoggerProvider(IDiagnosticEventRepositoryFactory diagnosticEventRepositoryFactory, IEnvironment environment)
16+
public DiagnosticEventLoggerProvider(IDiagnosticEventRepositoryFactory diagnosticEventRepositoryFactory, IEnvironment environment,
17+
IOptionsMonitor<StandbyOptions> standbyOptions)
1618
{
1719
_diagnosticEventRepositoryFactory = diagnosticEventRepositoryFactory ?? throw new ArgumentNullException(nameof(diagnosticEventRepositoryFactory));
1820
_environment = environment ?? throw new ArgumentNullException(nameof(environment));
21+
_standbyOptions = standbyOptions ?? throw new ArgumentNullException(nameof(standbyOptions));
1922
}
2023

2124
public ILogger CreateLogger(string categoryName)
2225
{
23-
return new DiagnosticEventLogger(_diagnosticEventRepositoryFactory, _environment);
26+
return new DiagnosticEventLogger(_diagnosticEventRepositoryFactory, _environment, _standbyOptions);
2427
}
2528

2629
public void Dispose()

‎src/WebJobs.Script.WebHost/Program.cs‎

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2,9 +2,7 @@
22
// Licensed under the MIT License. See License.txt in the project root for license information.
33

44
using System;
5-
using System.Collections;
65
using System.Linq;
7-
using System.Runtime.InteropServices;
86
using System.Threading;
97
using Microsoft.AspNetCore.Builder;
108
using Microsoft.AspNetCore.Hosting;

‎src/WebJobs.Script.WebHost/WebHostServiceCollectionExtensions.cs‎

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
// Copyright (c) .NET Foundation. All rights reserved.
22
// Licensed under the MIT License. See License.txt in the project root for license information.
33

4-
using System;
54
using System.IO.Abstractions;
65
using System.Net.Http;
76
using System.Runtime.InteropServices;
@@ -147,6 +146,12 @@ public static void AddWebJobsScriptHost(this IServiceCollection services, IConfi
147146

148147
// Logging and diagnostics
149148
services.AddSingleton<IMetricsLogger, WebHostMetricsLogger>();
149+
if (!FeatureFlags.IsEnabled(ScriptConstants.FeatureFlagDisableDiagnosticEventLogging))
150+
{
151+
services.AddSingleton<ILoggerProvider, DiagnosticEventLoggerProvider>();
152+
services.TryAddSingleton<IDiagnosticEventRepository, DiagnosticEventTableStorageRepository>();
153+
services.TryAddSingleton<IDiagnosticEventRepositoryFactory, DiagnosticEventRepositoryFactory>();
154+
}
150155

151156
// Secret management
152157
services.TryAddSingleton<ISecretManagerProvider, DefaultSecretManagerProvider>();

‎src/WebJobs.Script.WebHost/WebScriptHostBuilderExtension.cs‎

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -93,9 +93,8 @@ public static IHostBuilder AddWebScriptHost(this IHostBuilder builder, IServiceP
9393

9494
if (!FeatureFlags.IsEnabled(ScriptConstants.FeatureFlagDisableDiagnosticEventLogging))
9595
{
96+
// services that this depends on are registered at the webhost level
9697
loggingBuilder.Services.AddSingleton<ILoggerProvider, DiagnosticEventLoggerProvider>();
97-
loggingBuilder.Services.TryAddSingleton<IDiagnosticEventRepository, DiagnosticEventTableStorageRepository>();
98-
loggingBuilder.Services.TryAddSingleton<IDiagnosticEventRepositoryFactory, DiagnosticEventRepositoryFactory>();
9998
}
10099

101100
ConfigureRegisteredBuilders(loggingBuilder, rootServiceProvider);

‎src/WebJobs.Script/Diagnostics/DiagnosticEventConstants.cs‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
// Copyright (c) .NET Foundation. All rights reserved.
2+
// Licensed under the MIT License. See License.txt in the project root for license information.
3+
4+
namespace Microsoft.Azure.WebJobs.Script
5+
{
6+
internal static class DiagnosticEventConstants
7+
{
8+
public const string HostIdCollisionErrorCode = "AZFD004";
9+
public const string HostIdCollisionHelpLink = "https://go.microsoft.com/fwlink/?linkid=2224100";
10+
11+
public const string ExternalStartupErrorCode = "AZFD0005";
12+
public const string ExternalStartupErrorHelpLink = "https://go.microsoft.com/fwlink/?linkid=2224847";
13+
}
14+
}

‎src/WebJobs.Script/ExternalStartupException.cs‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,25 @@
1+
// Copyright (c) .NET Foundation. All rights reserved.
2+
// Licensed under the MIT License. See License.txt in the project root for license information.
3+
4+
using System;
5+
6+
namespace Microsoft.Azure.WebJobs.Script
7+
{
8+
/// <summary>
9+
/// An exception that indicates an issue calling into an external Startup class. This will
10+
/// prevent the host from starting.
11+
/// </summary>
12+
[Serializable]
13+
public class ExternalStartupException : Exception
14+
{
15+
public ExternalStartupException() { }
16+
17+
public ExternalStartupException(string message) : base(message) { }
18+
19+
public ExternalStartupException(string message, Exception inner) : base(message, inner) { }
20+
21+
protected ExternalStartupException(
22+
System.Runtime.Serialization.SerializationInfo info,
23+
System.Runtime.Serialization.StreamingContext context) : base(info, context) { }
24+
}
25+
}

‎src/WebJobs.Script/Host/HostIdValidator.cs‎

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -28,8 +28,6 @@ namespace Microsoft.Azure.WebJobs.Script
2828
public class HostIdValidator
2929
{
3030
public const string BlobPathFormat = "ids/usage/{0}";
31-
private const string HostIdCollisionErrorCode = "AZFD004";
32-
private const string HostIdCollisionHelpLink = "https://go.microsoft.com/fwlink/?linkid=2224100";
3331
private const LogLevel DefaultLevel = LogLevel.Error;
3432

3533
private readonly IEnvironment _environment;
@@ -125,15 +123,15 @@ private void HandleCollision(string hostId)
125123
{
126124
_logger.LogWarning(message);
127125

128-
DiagnosticEventLoggerExtensions.LogDiagnosticEventInformation(_logger, HostIdCollisionErrorCode, message, HostIdCollisionHelpLink);
126+
DiagnosticEventLoggerExtensions.LogDiagnosticEventInformation(_logger, DiagnosticEventConstants.HostIdCollisionErrorCode, message, DiagnosticEventConstants.HostIdCollisionHelpLink);
129127
}
130128
else
131129
{
132130
// We only allow Warning/Error levels to be specified,
133131
// so anything other than Warning is treated as Error.
134132
_logger.LogError(message);
135133

136-
DiagnosticEventLoggerExtensions.LogDiagnosticEventError(_logger, HostIdCollisionErrorCode, message, HostIdCollisionHelpLink, new InvalidOperationException(message));
134+
DiagnosticEventLoggerExtensions.LogDiagnosticEventError(_logger, DiagnosticEventConstants.HostIdCollisionErrorCode, message, DiagnosticEventConstants.HostIdCollisionHelpLink, new InvalidOperationException(message));
137135

138136
_applicationLifetime.StopApplication();
139137
}

‎src/WebJobs.Script/ScriptHostBuilderExtensions.cs‎

Lines changed: 54 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,11 @@
44
using System;
55
using System.Collections.Generic;
66
using System.Runtime.InteropServices;
7+
using Microsoft.ApplicationInsights;
8+
using Microsoft.ApplicationInsights.Channel;
9+
using Microsoft.ApplicationInsights.DataContracts;
710
using Microsoft.ApplicationInsights.Extensibility;
11+
using Microsoft.ApplicationInsights.Extensibility.Implementation;
812
using Microsoft.ApplicationInsights.WindowsServer.TelemetryChannel;
913
using Microsoft.Azure.WebJobs.Host;
1014
using Microsoft.Azure.WebJobs.Host.Executors;
@@ -209,7 +213,16 @@ public static IHostBuilder AddScriptHostCore(this IHostBuilder builder, ScriptAp
209213
// Only set our external startup if we're not suppressing host initialization
210214
// as we don't want to load user assemblies otherwise.
211215
var locator = context.Properties.GetAndRemove<ScriptStartupTypeLocator>(StartupTypeLocatorKey);
212-
webJobsBuilder.UseExternalStartup(locator, webJobsBuilderContext, loggerFactory);
216+
217+
try
218+
{
219+
webJobsBuilder.UseExternalStartup(locator, webJobsBuilderContext, loggerFactory);
220+
}
221+
catch (Exception ex)
222+
{
223+
string appInsightsConnStr = context.Configuration[EnvironmentSettingNames.AppInsightsConnectionString];
224+
RecordAndThrowExternalStartupException("Error configuring services in an external startup class.", ex, loggerFactory, appInsightsConnStr);
225+
}
213226
}
214227

215228
configureWebJobs?.Invoke(webJobsBuilder);
@@ -226,7 +239,19 @@ public static IHostBuilder AddScriptHostCore(this IHostBuilder builder, ScriptAp
226239
};
227240

228241
// Delay this call so we can call the customer's setup last.
229-
context.Properties[DelayedConfigurationActionKey] = new Action<IWebJobsStartupTypeLocator>(locator => webJobsConfigBuilder.UseExternalConfigurationStartup(locator, webJobsBuilderContext, loggerFactory));
242+
context.Properties[DelayedConfigurationActionKey] = new Action<IWebJobsStartupTypeLocator>(locator =>
243+
{
244+
try
245+
{
246+
webJobsConfigBuilder.UseExternalConfigurationStartup(locator, webJobsBuilderContext, loggerFactory);
247+
}
248+
catch (Exception ex)
249+
{
250+
// Go directly to the environment; We have no valid configuration from the customer at this point.
251+
string appInsightsConnStr = Environment.GetEnvironmentVariable(EnvironmentSettingNames.AppInsightsConnectionString);
252+
RecordAndThrowExternalStartupException("Error building configuration in an external startup class.", ex, loggerFactory, appInsightsConnStr);
253+
}
254+
});
230255
}
231256
});
232257

@@ -476,5 +501,32 @@ private static T GetAndRemove<T>(this IDictionary<object, object> dictionary, st
476501
throw new InvalidOperationException($"The key '{key}' does not exist in the dictionary.");
477502
}
478503
}
504+
505+
private static void RecordAndThrowExternalStartupException(string message, Exception ex, ILoggerFactory loggerFactory, string appInsightsConnStr)
506+
{
507+
var startupEx = new ExternalStartupException(message, ex);
508+
509+
var logger = loggerFactory.CreateLogger(LogCategories.Startup);
510+
logger.LogDiagnosticEventError(DiagnosticEventConstants.ExternalStartupErrorCode, message, DiagnosticEventConstants.ExternalStartupErrorHelpLink, startupEx);
511+
512+
// Send the error to App Insights if possible. This is happening during ScriptHost construction so we
513+
// have no existing TelemetryClient to use. Create a one-off client and flush it ASAP.
514+
if (appInsightsConnStr is not null)
515+
{
516+
using TelemetryConfiguration telemetryConfiguration = new()
517+
{
518+
ConnectionString = appInsightsConnStr,
519+
TelemetryChannel = new InMemoryChannel()
520+
};
521+
522+
TelemetryClient telemetryClient = new(telemetryConfiguration);
523+
telemetryClient.Context.GetInternalContext().SdkVersion = new ApplicationInsightsSdkVersionProvider().GetSdkVersion();
524+
telemetryClient.TrackTrace(startupEx.ToString(), SeverityLevel.Error);
525+
telemetryClient.TrackException(startupEx);
526+
telemetryClient.Flush();
527+
}
528+
529+
throw startupEx;
530+
}
479531
}
480532
}

‎test/CSharpPrecompiledTestProjects/WebJobsStartupTests/Startup.cs‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,12 @@ public void Configure(WebJobsBuilderContext context, IWebJobsBuilder builder)
2727
{
2828
config.GetSection("MyOptions").Bind(options);
2929
});
30+
31+
string message = Environment.GetEnvironmentVariable("SERVICE_THROW");
32+
if (message != null)
33+
{
34+
throw new InvalidOperationException(message);
35+
}
3036
}
3137

3238
public void Configure(WebJobsBuilderContext context, IWebJobsConfigurationBuilder builder)
@@ -39,6 +45,12 @@ public void Configure(WebJobsBuilderContext context, IWebJobsConfigurationBuilde
3945
{ "SomeOtherKey", "SomeOtherValue" },
4046
{ "Cron", "0 0 0 1 1 0" }
4147
});
48+
49+
string message = Environment.GetEnvironmentVariable("CONFIG_THROW");
50+
if (message != null)
51+
{
52+
throw new InvalidOperationException(message);
53+
}
4254
}
4355

4456
private static void ValidateContext(WebJobsBuilderContext context)

0 commit comments

Comments
 (0)