Refactor logging and profiling, boot reporting

This commit is contained in:
Stephan
2016-09-11 19:57:33 +02:00
parent 091816a2ea
commit 5c2232aa3b
168 changed files with 1498 additions and 1281 deletions

View File

@@ -10,12 +10,16 @@ namespace Umbraco.Web.Scheduling
internal class KeepAlive : RecurringTaskBase
{
private readonly IRuntimeState _runtime;
private readonly ILogger _logger;
private readonly ProfilingLogger _proflog;
public KeepAlive(IBackgroundTaskRunner<RecurringTaskBase> runner, int delayMilliseconds, int periodMilliseconds,
IRuntimeState runtime)
IRuntimeState runtime, ILogger logger, ProfilingLogger proflog)
: base(runner, delayMilliseconds, periodMilliseconds)
{
_runtime = runtime;
_logger = logger;
_proflog = proflog;
}
public override bool PerformRun()
@@ -28,11 +32,11 @@ namespace Umbraco.Web.Scheduling
// ensure we do not run if not main domain, but do NOT lock it
if (_runtime.IsMainDom == false)
{
LogHelper.Debug<KeepAlive>("Does not run if not MainDom.");
_logger.Debug<KeepAlive>("Does not run if not MainDom.");
return false; // do NOT repeat, going down
}
using (DisposableTimer.DebugDuration<KeepAlive>(() => "Keep alive executing", () => "Keep alive complete"))
using (_proflog.DebugDuration<KeepAlive>("Keep alive executing", "Keep alive complete"))
{
string umbracoAppUrl = null;
@@ -41,7 +45,7 @@ namespace Umbraco.Web.Scheduling
umbracoAppUrl = _runtime.ApplicationUrl.ToString();
if (umbracoAppUrl.IsNullOrWhiteSpace())
{
LogHelper.Warn<KeepAlive>("No url for service (yet), skip.");
_logger.Warn<KeepAlive>("No url for service (yet), skip.");
return true; // repeat
}
@@ -54,7 +58,7 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception e)
{
LogHelper.Error<KeepAlive>(string.Format("Failed (at \"{0}\").", umbracoAppUrl), e);
_logger.Error<KeepAlive>(string.Format("Failed (at \"{0}\").", umbracoAppUrl), e);
}
}

View File

@@ -14,18 +14,22 @@ namespace Umbraco.Web.Scheduling
private readonly IRuntimeState _runtime;
private readonly IAuditService _auditService;
private readonly IUmbracoSettingsSection _settings;
private readonly ILogger _logger;
private readonly ProfilingLogger _proflog;
public LogScrubber(IBackgroundTaskRunner<RecurringTaskBase> runner, int delayMilliseconds, int periodMilliseconds,
IRuntimeState runtime, IAuditService auditService, IUmbracoSettingsSection settings)
IRuntimeState runtime, IAuditService auditService, IUmbracoSettingsSection settings, ILogger logger, ProfilingLogger proflog)
: base(runner, delayMilliseconds, periodMilliseconds)
{
_runtime = runtime;
_auditService = auditService;
_settings = settings;
_logger = logger;
_proflog = proflog;
}
// maximum age, in minutes
private static int GetLogScrubbingMaximumAge(IUmbracoSettingsSection settings)
private int GetLogScrubbingMaximumAge(IUmbracoSettingsSection settings)
{
var maximumAge = 24 * 60; // 24 hours, in minutes
try
@@ -35,13 +39,13 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception e)
{
LogHelper.Error<LogScrubber>("Unable to locate a log scrubbing maximum age. Defaulting to 24 hours.", e);
_logger.Error<LogScrubber>("Unable to locate a log scrubbing maximum age. Defaulting to 24 hours.", e);
}
return maximumAge;
}
public static int GetLogScrubbingInterval(IUmbracoSettingsSection settings)
public static int GetLogScrubbingInterval(IUmbracoSettingsSection settings, ILogger logger)
{
var interval = 4 * 60 * 60 * 1000; // 4 hours, in milliseconds
try
@@ -51,7 +55,7 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception e)
{
LogHelper.Error<LogScrubber>("Unable to locate a log scrubbing interval. Defaulting to 4 hours.", e);
logger.Error<LogScrubber>("Unable to locate a log scrubbing interval. Defaulting to 4 hours.", e);
}
return interval;
}
@@ -61,21 +65,21 @@ namespace Umbraco.Web.Scheduling
switch (_runtime.ServerRole)
{
case ServerRole.Slave:
LogHelper.Debug<LogScrubber>("Does not run on slave servers.");
_logger.Debug<LogScrubber>("Does not run on slave servers.");
return true; // DO repeat, server role can change
case ServerRole.Unknown:
LogHelper.Debug<LogScrubber>("Does not run on servers with unknown role.");
_logger.Debug<LogScrubber>("Does not run on servers with unknown role.");
return true; // DO repeat, server role can change
}
// ensure we do not run if not main domain, but do NOT lock it
if (_runtime.IsMainDom == false)
{
LogHelper.Debug<LogScrubber>("Does not run if not MainDom.");
_logger.Debug<LogScrubber>("Does not run if not MainDom.");
return false; // do NOT repeat, going down
}
using (DisposableTimer.DebugDuration<LogScrubber>("Log scrubbing executing", "Log scrubbing complete"))
using (_proflog.DebugDuration<LogScrubber>("Log scrubbing executing", "Log scrubbing complete"))
{
_auditService.CleanLogs(GetLogScrubbingMaximumAge(_settings));
}

View File

@@ -14,13 +14,17 @@ namespace Umbraco.Web.Scheduling
{
private readonly IRuntimeState _runtime;
private readonly IUserService _userService;
private readonly ILogger _logger;
private readonly ProfilingLogger _proflog;
public ScheduledPublishing(IBackgroundTaskRunner<RecurringTaskBase> runner, int delayMilliseconds, int periodMilliseconds,
IRuntimeState runtime, IUserService userService)
IRuntimeState runtime, IUserService userService, ILogger logger, ProfilingLogger proflog)
: base(runner, delayMilliseconds, periodMilliseconds)
{
_runtime = runtime;
_userService = userService;
_logger = logger;
_proflog = proflog;
}
public override bool PerformRun()
@@ -33,21 +37,21 @@ namespace Umbraco.Web.Scheduling
switch (_runtime.ServerRole)
{
case ServerRole.Slave:
LogHelper.Debug<ScheduledPublishing>("Does not run on slave servers.");
_logger.Debug<ScheduledPublishing>("Does not run on slave servers.");
return true; // DO repeat, server role can change
case ServerRole.Unknown:
LogHelper.Debug<ScheduledPublishing>("Does not run on servers with unknown role.");
_logger.Debug<ScheduledPublishing>("Does not run on servers with unknown role.");
return true; // DO repeat, server role can change
}
// ensure we do not run if not main domain, but do NOT lock it
if (_runtime.IsMainDom == false)
{
LogHelper.Debug<ScheduledPublishing>("Does not run if not MainDom.");
_logger.Debug<ScheduledPublishing>("Does not run if not MainDom.");
return false; // do NOT repeat, going down
}
using (DisposableTimer.DebugDuration<ScheduledPublishing>(() => "Scheduled publishing executing", () => "Scheduled publishing complete"))
using (_proflog.DebugDuration<ScheduledPublishing>("Scheduled publishing executing", "Scheduled publishing complete"))
{
string umbracoAppUrl = null;
@@ -56,7 +60,7 @@ namespace Umbraco.Web.Scheduling
umbracoAppUrl = _runtime.ApplicationUrl.ToString();
if (umbracoAppUrl.IsNullOrWhiteSpace())
{
LogHelper.Warn<ScheduledPublishing>("No url for service (yet), skip.");
_logger.Warn<ScheduledPublishing>("No url for service (yet), skip.");
return true; // repeat
}
@@ -75,7 +79,7 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception e)
{
LogHelper.Error<ScheduledPublishing>(string.Format("Failed (at \"{0}\").", umbracoAppUrl), e);
_logger.Error<ScheduledPublishing>(string.Format("Failed (at \"{0}\").", umbracoAppUrl), e);
}
}

View File

@@ -19,14 +19,18 @@ namespace Umbraco.Web.Scheduling
{
private readonly IRuntimeState _runtime;
private readonly IUmbracoSettingsSection _settings;
private readonly ILogger _logger;
private readonly ProfilingLogger _proflog;
private static readonly Hashtable ScheduledTaskTimes = new Hashtable();
public ScheduledTasks(IBackgroundTaskRunner<RecurringTaskBase> runner, int delayMilliseconds, int periodMilliseconds,
IRuntimeState runtime, IUmbracoSettingsSection settings)
IRuntimeState runtime, IUmbracoSettingsSection settings, ILogger logger, ProfilingLogger proflog)
: base(runner, delayMilliseconds, periodMilliseconds)
{
_runtime = runtime;
_settings = settings;
_logger = logger;
_proflog = proflog;
}
private async Task ProcessTasksAsync(CancellationToken token)
@@ -54,7 +58,7 @@ namespace Umbraco.Web.Scheduling
{
var taskResult = await GetTaskByHttpAync(t.Url, token);
if (t.Log)
LogHelper.Info<ScheduledTasks>(string.Format("{0} has been called with response: {1}", t.Alias, taskResult));
_logger.Info<ScheduledTasks>(string.Format("{0} has been called with response: {1}", t.Alias, taskResult));
}
}
}
@@ -75,7 +79,7 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception ex)
{
LogHelper.Error<ScheduledTasks>("An error occurred calling web task for url: " + url, ex);
_logger.Error<ScheduledTasks>("An error occurred calling web task for url: " + url, ex);
}
return false;
}
@@ -91,21 +95,21 @@ namespace Umbraco.Web.Scheduling
switch (_runtime.ServerRole)
{
case ServerRole.Slave:
LogHelper.Debug<ScheduledTasks>("Does not run on slave servers.");
_logger.Debug<ScheduledTasks>("Does not run on slave servers.");
return true; // DO repeat, server role can change
case ServerRole.Unknown:
LogHelper.Debug<ScheduledTasks>("Does not run on servers with unknown role.");
_logger.Debug<ScheduledTasks>("Does not run on servers with unknown role.");
return true; // DO repeat, server role can change
}
// ensure we do not run if not main domain, but do NOT lock it
if (_runtime.IsMainDom == false)
{
LogHelper.Debug<ScheduledTasks>("Does not run if not MainDom.");
_logger.Debug<ScheduledTasks>("Does not run if not MainDom.");
return false; // do NOT repeat, going down
}
using (DisposableTimer.DebugDuration<ScheduledTasks>(() => "Scheduled tasks executing", () => "Scheduled tasks complete"))
using (_proflog.DebugDuration<ScheduledTasks>("Scheduled tasks executing", "Scheduled tasks complete"))
{
try
{
@@ -113,7 +117,7 @@ namespace Umbraco.Web.Scheduling
}
catch (Exception ee)
{
LogHelper.Error<ScheduledTasks>("Error executing scheduled task", ee);
_logger.Error<ScheduledTasks>("Error executing scheduled task", ee);
}
}

View File

@@ -21,6 +21,8 @@ namespace Umbraco.Web.Scheduling
private IRuntimeState _runtime;
private IUserService _userService;
private IAuditService _auditService;
private ILogger _logger;
private ProfilingLogger _proflog;
private BackgroundTaskRunner<IBackgroundTask> _keepAliveRunner;
private BackgroundTaskRunner<IBackgroundTask> _publishingRunner;
@@ -31,11 +33,13 @@ namespace Umbraco.Web.Scheduling
private object _locker = new object();
private IBackgroundTask[] _tasks;
public void Initialize(IRuntimeState runtime, IUserService userService, IAuditService auditService, ILogger logger)
public void Initialize(IRuntimeState runtime, IUserService userService, IAuditService auditService, ILogger logger, ProfilingLogger proflog)
{
_runtime = runtime;
_userService = userService;
_auditService = auditService;
_logger = logger;
_proflog = proflog;
// backgrounds runners are web aware, if the app domain dies, these tasks will wind down correctly
_keepAliveRunner = new BackgroundTaskRunner<IBackgroundTask>("KeepAlive", logger);
@@ -65,15 +69,15 @@ namespace Umbraco.Web.Scheduling
LazyInitializer.EnsureInitialized(ref _tasks, ref _started, ref _locker, () =>
{
LogHelper.Debug<SchedulerComponent>(() => "Initializing the scheduler");
_logger.Debug<SchedulerComponent>(() => "Initializing the scheduler");
var settings = UmbracoConfig.For.UmbracoSettings();
var tasks = new List<IBackgroundTask>
{
new KeepAlive(_keepAliveRunner, 60000, 300000, _runtime),
new ScheduledPublishing(_publishingRunner, 60000, 60000, _runtime, _userService),
new ScheduledTasks(_tasksRunner, 60000, 60000, _runtime, settings),
new LogScrubber(_scrubberRunner, 60000, LogScrubber.GetLogScrubbingInterval(settings), _runtime, _auditService, settings)
new KeepAlive(_keepAliveRunner, 60000, 300000, _runtime, _logger, _proflog),
new ScheduledPublishing(_publishingRunner, 60000, 60000, _runtime, _userService, _logger, _proflog),
new ScheduledTasks(_tasksRunner, 60000, 60000, _runtime, settings, _logger, _proflog),
new LogScrubber(_scrubberRunner, 60000, LogScrubber.GetLogScrubbingInterval(settings, _logger), _runtime, _auditService, settings, _logger, _proflog)
};
// ping/keepalive