private async Task RunRuleAsync(Entry entry)
{
Contract.AssertNotNull(entry);
var rule = entry.Rule;
var stopwatch = new Stopwatch();
var failed = false;
RuleContext context = null;
Exception exception = null;
try
{
await _runGate.WaitAsync();
lock (entry.Lock)
{
Contract.Assert(entry.State == State.Scheduled);
entry.State = State.Running;
}
_logger.Debug($"Running rule `{rule.Identifier}`. `{_runGate.CurrentCount}` more allowed to run");
context = new RuleContext(Guid.NewGuid(), _clock.UtcNow);
stopwatch.Restart();
await rule.Run(context);
}
catch (Exception thrownException)
{
failed = true;
exception = thrownException;
}
finally
{
stopwatch.Stop();
_runGate.Release();
lock (entry.Lock)
{
entry.LastRunTimeUtc = _clock.UtcNow;
Contract.Assert(entry.State == State.Running);
entry.State = failed ? State.Failed : State.Waiting;
var logMessage = $"Rule `{rule.Identifier}` finished running @ `{entry.LastRunTimeUtc}`, took {stopwatch.Elapsed} to run";
if (!failed)
{
_logger.Debug(logMessage);
}
else
{
_logger.Error($"{logMessage}. An exception has been caught and the rule has been disabled. Exception: {exception?.ToString() ?? "N/A"}");
}
}
_notifier?.Emit(new LogEntry
{
RunTimeUtc = context?.RunTimeUtc ?? _clock.UtcNow,
RuleIdentifier = rule.Identifier,
RunGuid = context?.RunGuid ?? Guid.Empty,
Elapsed = stopwatch.Elapsed,
ErrorMessage = failed ? exception?.ToString() : "",
});
}
}
private async Task RunRuleAsync(Entry entry, CancellationToken cancellationToken)
{
Contract.AssertNotNull(entry);
var rule = entry.Rule;
if (!_concurrencyBuckets.TryGetValue(rule.ConcurrencyBucket, out var runGate) || runGate == null)
{
// If we can't find the bucket, or if it is set to explicitly have no limit, we just use the no-limit
// bucket.
runGate = _defaultConcurrencyBucket;
}
var stopwatch = Stopwatch.StartNew();
var failed = false;
RuleContext?context = null;
Exception? exception = null;
var runGateLockTaken = false;
try
{
await runGate.WaitAsync(cancellationToken);
runGateLockTaken = true;
lock (entry.Lock)
{
Contract.Assert(entry.State == State.Scheduled);
entry.State = State.Running;
}
_logger.Debug($"Running rule `{rule.Identifier}`. `{runGate.CurrentCount}` more allowed to run. Delayed for {stopwatch.Elapsed}");
context = new RuleContext(Guid.NewGuid(), _clock.UtcNow, cancellationToken);
stopwatch.Restart();
await rule.Run(context);
}
catch (Exception thrownException)
{
failed = true;
exception = thrownException;
}
finally
{
stopwatch.Stop();
if (runGateLockTaken)
{
runGate.Release();
lock (entry.Lock)
{
entry.LastRunTimeUtc = _clock.UtcNow;
Contract.Assert(entry.State == State.Running);
entry.State = failed ? State.Failed : State.Waiting;
var logMessage = $"Rule `{rule.Identifier}` finished running @ `{entry.LastRunTimeUtc}`, took {stopwatch.Elapsed} to run";
if (!failed)
{
_logger.Debug(logMessage);
}
else
{
_logger.Error($"{logMessage}. An exception has been caught and the rule has been disabled. Exception: {exception?.ToString() ?? "N/A"}");
}
}
_notifier?.Emit(new LogEntry
{
RunTimeUtc = context?.RunTimeUtc ?? _clock.UtcNow,
RuleIdentifier = rule.Identifier,
RunGuid = context?.RunGuid ?? Guid.Empty,
Elapsed = stopwatch.Elapsed,
ErrorMessage = failed ? exception?.ToString() : "",
});
}
else
{
_logger.Debug($"Rule `{rule.Identifier}` was cancelled");
}
}
}
