Skip to content

Commit cf40d87

Browse files
pragnagopapragnagopa
authored
Add startup logs (#5146)
1 parent 7685cbe commit cf40d87

File tree

3 files changed

+71
-54
lines changed

3 files changed

+71
-54
lines changed

‎src/WebJobs.Script.WebHost/App_Start/WebHostResolver.cs‎

Lines changed: 66 additions & 54 deletions
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@ public sealed class WebHostResolver : IDisposable
3535
private ILoggerFactory _defaultLoggerFactory;
3636
private TraceWriter _defaultTraceWriter;
3737
private Timer _specializationTimer;
38+
private ILogger _logger;
3839

3940
public WebHostResolver(ScriptSettingsManager settingsManager, ISecretManagerFactory secretManagerFactory, IScriptEventManager eventManager)
4041
{
@@ -123,74 +124,85 @@ public WebHookReceiverManager GetWebHookReceiverManager(WebHostSettings settings
123124
/// </summary>
124125
internal void EnsureInitialized(WebHostSettings settings)
125126
{
126-
lock (_syncLock)
127+
ILoggerFactory defaultLoggerFactory = GetDefaultLoggerFactory(settings);
128+
_logger = defaultLoggerFactory.CreateLogger(ScriptConstants.LogCategoryHostStartup);
129+
try
127130
{
128-
// Determine whether we should do normal or standby initialization
129-
if (!WebScriptHostManager.InStandbyMode)
131+
lock (_syncLock)
130132
{
131-
// We're not in standby mode. There are two cases to consider:
132-
// 1) We _were_ in standby mode and now we're ready to specialize
133-
// 2) We're doing non-specialization normal initialization
134-
if (_activeHostManager == null &&
135-
(_standbyHostManager == null || (_settingsManager.ContainerReady && _settingsManager.ConfigurationReady)))
133+
// Determine whether we should do normal or standby initialization
134+
if (!WebScriptHostManager.InStandbyMode)
136135
{
137-
_specializationTimer?.Dispose();
138-
_specializationTimer = null;
136+
// We're not in standby mode. There are two cases to consider:
137+
// 1) We _were_ in standby mode and now we're ready to specialize
138+
// 2) We're doing non-specialization normal initialization
139+
if (_activeHostManager == null &&
140+
(_standbyHostManager == null || (_settingsManager.ContainerReady && _settingsManager.ConfigurationReady)))
141+
{
142+
_logger.LogDebug("Not in standby mode.Initializing host");
139143

140-
_activeScriptHostConfig = CreateScriptHostConfiguration(settings);
141-
var defaultLoggerFactory = GetDefaultLoggerFactory(settings);
142-
_activeHostManager = new WebScriptHostManager(_activeScriptHostConfig, _secretManagerFactory, _eventManager, _settingsManager, settings, defaultLoggerFactory);
143-
_activeReceiverManager = new WebHookReceiverManager(_activeHostManager.SecretManager);
144-
InitializeFileSystem(_settingsManager.FileSystemIsReadOnly);
144+
_specializationTimer?.Dispose();
145+
_specializationTimer = null;
145146

146-
if (_standbyHostManager != null)
147-
{
148-
// we're starting the one and only one
149-
// standby mode specialization
150-
_activeScriptHostConfig.TraceWriter.Info(Resources.HostSpecializationTrace);
147+
_activeScriptHostConfig = CreateScriptHostConfiguration(settings);
148+
_activeHostManager = new WebScriptHostManager(_activeScriptHostConfig, _secretManagerFactory, _eventManager, _settingsManager, settings, defaultLoggerFactory);
149+
_activeReceiverManager = new WebHookReceiverManager(_activeHostManager.SecretManager);
150+
InitializeFileSystem(_settingsManager.FileSystemIsReadOnly);
151+
152+
if (_standbyHostManager != null)
153+
{
154+
// we're starting the one and only one
155+
// standby mode specialization
156+
_activeScriptHostConfig.TraceWriter.Info(Resources.HostSpecializationTrace);
151157

152-
// After specialization, we need to ensure that custom timezone
153-
// settings configured by the user (WEBSITE_TIME_ZONE) are honored.
154-
// DateTime caches timezone information, so we need to clear the cache.
155-
TimeZoneInfo.ClearCachedData();
158+
// After specialization, we need to ensure that custom timezone
159+
// settings configured by the user (WEBSITE_TIME_ZONE) are honored.
160+
// DateTime caches timezone information, so we need to clear the cache.
161+
TimeZoneInfo.ClearCachedData();
156162

157-
// ensure we reinitialize hostname after specialization
158-
HostNameProvider.Reset();
159-
}
163+
// ensure we reinitialize hostname after specialization
164+
HostNameProvider.Reset();
165+
}
160166

161-
if (_standbyHostManager != null)
162-
{
163-
_standbyHostManager.Stop();
164-
_standbyHostManager.Dispose();
167+
if (_standbyHostManager != null)
168+
{
169+
_standbyHostManager.Stop();
170+
_standbyHostManager.Dispose();
171+
}
172+
_standbyReceiverManager?.Dispose();
173+
_standbyScriptHostConfig = null;
174+
_standbyHostManager = null;
175+
_standbyReceiverManager = null;
165176
}
166-
_standbyReceiverManager?.Dispose();
167-
_standbyScriptHostConfig = null;
168-
_standbyHostManager = null;
169-
_standbyReceiverManager = null;
170177
}
171-
}
172-
else
173-
{
174-
// We're in standby (placeholder) mode. Initialize the standby services.
175-
if (_standbyHostManager == null)
178+
else
176179
{
177-
var standbySettings = CreateStandbySettings(settings);
178-
_standbyScriptHostConfig = CreateScriptHostConfiguration(standbySettings, true);
179-
var defaultLoggerFactory = GetDefaultLoggerFactory(settings);
180-
_standbyHostManager = new WebScriptHostManager(_standbyScriptHostConfig, _secretManagerFactory, _eventManager, _settingsManager, standbySettings, defaultLoggerFactory);
181-
_standbyReceiverManager = new WebHookReceiverManager(_standbyHostManager.SecretManager);
182-
183-
InitializeFileSystem(_settingsManager.FileSystemIsReadOnly);
184-
StandbyManager.Initialize(_standbyScriptHostConfig);
185-
186-
// start a background timer to identify when specialization happens
187-
// specialization usually happens via an http request (e.g. scale controller
188-
// ping) but this timer is started as well to handle cases where we
189-
// might not receive a request
190-
_specializationTimer = new Timer(OnSpecializationTimerTick, settings, 1000, 1000);
180+
// We're in standby (placeholder) mode. Initialize the standby services.
181+
if (_standbyHostManager == null)
182+
{
183+
_logger.LogDebug("In standby mode");
184+
var standbySettings = CreateStandbySettings(settings);
185+
_standbyScriptHostConfig = CreateScriptHostConfiguration(standbySettings, true);
186+
_standbyHostManager = new WebScriptHostManager(_standbyScriptHostConfig, _secretManagerFactory, _eventManager, _settingsManager, standbySettings, defaultLoggerFactory);
187+
_standbyReceiverManager = new WebHookReceiverManager(_standbyHostManager.SecretManager);
188+
189+
InitializeFileSystem(_settingsManager.FileSystemIsReadOnly);
190+
StandbyManager.Initialize(_standbyScriptHostConfig);
191+
192+
// start a background timer to identify when specialization happens
193+
// specialization usually happens via an http request (e.g. scale controller
194+
// ping) but this timer is started as well to handle cases where we
195+
// might not receive a request
196+
_specializationTimer = new Timer(OnSpecializationTimerTick, settings, 1000, 1000);
197+
}
191198
}
192199
}
193200
}
201+
catch (Exception initializationException)
202+
{
203+
var errorEventId = new EventId(103, "HostInitializationError");
204+
_logger.LogError(errorEventId, initializationException, "Failed to initialize host");
205+
}
194206
}
195207

196208
internal static WebHostSettings CreateStandbySettings(WebHostSettings settings)

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

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -453,6 +453,7 @@ private async void OnSyncTimerTick(object state)
453453

454454
private void InitializeHttp()
455455
{
456+
_logger.LogDebug("Initializing HttpRequestManager");
456457
// get the registered http configuration from the extension registry
457458
var extensions = Instance.ScriptConfig.HostConfig.GetService<IExtensionRegistry>();
458459
var httpConfig = extensions.GetExtensions<IExtensionConfigProvider>().OfType<HttpExtensionConfiguration>().Single();
@@ -464,10 +465,12 @@ private void InitializeHttp()
464465
// since the request manager is created based on configurable
465466
// settings, it has to be recreated when host config changes
466467
_httpRequestManager = new WebScriptHostRequestManager(httpConfig, PerformanceManager, _metricsLogger, _config.TraceWriter);
468+
_logger.LogDebug("Initialized HttpRequestManager");
467469
}
468470

469471
private void InitializeHttpFunctions(IEnumerable<FunctionDescriptor> functions, HttpExtensionConfiguration httpConfig)
470472
{
473+
_logger.LogDebug("Initializing HttpFunctions");
471474
// we must initialize the route factory here AFTER full configuration
472475
// has been resolved so we apply any route prefix customizations
473476
var functionHttpRouteFactory = new HttpRouteFactory(httpConfig.RoutePrefix);
@@ -486,6 +489,7 @@ private void InitializeHttpFunctions(IEnumerable<FunctionDescriptor> functions,
486489
var httpRouteFactory = function.Metadata.IsProxy ? proxyHttpRouteFactory : functionHttpRouteFactory;
487490
httpRouteFactory.TryAddRoute(_httpRoutes, function);
488491
}
492+
_logger.LogDebug("Initialized HttpFunctions");
489493
}
490494

491495
public override void Shutdown(bool hard = false)

‎src/WebJobs.Script/ScriptConstants.cs‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,7 @@ public static class ScriptConstants
4545
public const string LogCategoryKeysController = "Host.Controllers.Keys";
4646
public const string LogCategoryKeys = "Host.Keys";
4747
public const string LogCategoryHostGeneral = "Host.General";
48+
public const string LogCategoryHostStartup = "Host.Startup";
4849

4950
// Define all system parameters we inject with a prefix to avoid collisions
5051
// with user parameters

0 commit comments

Comments
 (0)