public void ShouldPassCurrentTimeAndTradesToReportBuilder()
{
var dateTime = new DateTime(2019, 09, 25, 13, 45, 37);
Mock.Get(_timeProvider).Setup(x => x.GetCurrentTime()).Returns(dateTime);
_job.ExecuteAsync().Wait();
Mock.Get(_reportBuilder).Verify(x => x.PrepareReport(dateTime, It.IsAny <IEnumerable <Trade> >()), Times.Once());
}
private async Task ExecuteJobAsync(JobRegistration registration, IJob job, CancellationToken cancellationToken, string[] args = null)
{
if (registration?.Key.IsNullOrEmpty() == false && job != null)
{
try
{
async Task Execute()
{
// TODO: publish domain event (job started)
this.logger.LogJournal(LogEventPropertyKeys.TrackStartJob, $"{{LogKey:l}} job started (key={{JobKey}}, id={registration.Identifier}, type={job.GetType().PrettyName()}, isReentrant={registration.IsReentrant}, timeout={registration.Timeout.ToString("c")})", args: new[] { LogEventKeys.JobScheduling, registration.Key });
await job.ExecuteAsync(cancellationToken, args).AnyContext();
await Run.DelayedAsync(new TimeSpan(0, 0, 1), () =>
{
this.logger.LogJournal(LogEventPropertyKeys.TrackFinishJob, $"{{LogKey:l}} job finished (key={{JobKey}}, id={registration.Identifier}, type={job.GetType().PrettyName()})", args: new[] { LogEventKeys.JobScheduling, registration.Key });
return(Task.CompletedTask);
});
// TODO: publish domain event (job finished)
}
if (!registration.IsReentrant)
{
if (this.mutex.TryAcquireLock(registration.Key))
{
try
{
await Execute();
}
finally
{
this.mutex.ReleaseLock(registration.Key);
}
}
else
{
this.logger.LogWarning($"{{LogKey:l}} already executing (key={{JobKey}}, type={job.GetType().PrettyName()})", LogEventKeys.JobScheduling, registration.Key);
}
}
else
{
await Execute();
}
}
catch (OperationCanceledException ex)
{
// TODO: publish domain event (job failed)
this.logger.LogWarning(ex, $"{{LogKey:l}} canceled (key={{JobKey}}), type={job.GetType().PrettyName()})", LogEventKeys.JobScheduling, registration.Key);
//this.errorHandler?.Invoke(ex);
}
catch (Exception ex)
{
// TODO: publish domain event (job failed)
this.logger.LogError(ex.InnerException ?? ex, $"{{LogKey:l}} failed (key={{JobKey}}), type={job.GetType().PrettyName()})", LogEventKeys.JobScheduling, registration.Key);
this.errorHandler?.Invoke(ex.InnerException ?? ex);
}
}
}
private Task RunJob()
{
_logger.Debug($"Executing {_job} ...");
var task = _job.ExecuteAsync();
task.ContinueWith(OnJobFault, TaskContinuationOptions.OnlyOnFaulted);
task.ContinueWith(OnJobCompleted, TaskContinuationOptions.OnlyOnRanToCompletion);
return(task);
}
private async Task ExecuteJobAsync(IJob job)
{
try
{
await job.ExecuteAsync(externalToken);
await jobRepository.UpdateAsync(job);
}
catch (Exception exception)
{
OnJobExecutionFailed(job, exception);
}
}
private async Task ExecuteJobAsync(JobRegistration registration, IJob job, CancellationToken cancellationToken, string[] args = null)
{
if (registration?.Key.IsNullOrEmpty() == false && job != null)
{
try
{
async Task ExecuteAsync()
{
var correlationId = IdGenerator.Instance.Next;
using (var timer = new Foundation.Timer())
using (this.logger.BeginScope(new Dictionary <string, object>
{
[LogPropertyKeys.CorrelationId] = correlationId
}))
{
// TODO: publish domain event (job started)
this.logger.LogJournal(LogKeys.JobScheduling, $"job started: {{JobKey:l}} (id={registration.Identifier}, type={job.GetType().PrettyName()}, isReentrant={registration.IsReentrant}, timeout={registration.Timeout:c})", LogPropertyKeys.TrackStartJob, args: new[] { registration.Key });
//using (var scope = this.tracer?.BuildSpan($"job run {registration.Key}", LogKeys.JobScheduling, SpanKind.Producer).Activate(this.logger))
//{ // current span is somehow not available in created jobs (ServiceProviderJobFactory)
try
{
await job.ExecuteAsync(correlationId, cancellationToken, args).AnyContext();
this.logger.LogJournal(LogKeys.JobScheduling, $"job finished: {{JobKey:l}} (id={registration.Identifier}, type={job.GetType().PrettyName()})", LogPropertyKeys.TrackFinishJob, args: new[] { registration.Key });
}
catch (Exception ex)
{
this.logger.LogError(ex, $"{{LogKey:l}} job failed: {{JobKey:l}} (id={registration.Identifier}, type={job.GetType().PrettyName()}) {ex.GetFullMessage()}", args: new[] { LogKeys.JobScheduling, registration.Key });
}
// TODO: publish domain event (job finished)
}
}
if (!registration.IsReentrant)
{
if (this.mutex.TryAcquireLock(registration.Key))
{
try
{
await ExecuteAsync().AnyContext();
}
finally
{
this.mutex.ReleaseLock(registration.Key);
}
}
else
{
this.logger.LogWarning($"{{LogKey:l}} already executing (key={{JobKey:l}}, type={job.GetType().PrettyName()})", LogKeys.JobScheduling, registration.Key);
}
}
else
{
await ExecuteAsync().AnyContext();
}
}
catch (OperationCanceledException ex)
{
// TODO: publish domain event (job failed)
this.logger.LogWarning(ex, $"{{LogKey:l}} canceled (key={{JobKey:l}}), type={job.GetType().PrettyName()})", LogKeys.JobScheduling, registration.Key);
//this.errorHandler?.Invoke(ex);
}
catch (Exception ex)
{
// TODO: publish domain event (job failed)
this.logger.LogError(ex.InnerException ?? ex, $"{{LogKey:l}} failed (key={{JobKey:l}}), type={job.GetType().PrettyName()})", LogKeys.JobScheduling, registration.Key);
this.errorHandler?.Invoke(ex.InnerException ?? ex);
}
}
}
private async Task JobRunnerAsync(IJob job, CancellationToken jobCancellationToken)
{
if (job.NextScheduledTime == null)
{
_logger.LogWarning($"{job.Name} does not have any scheduled time, the job is not started.");
return;
}
using (var linkedTokenSource = CancellationTokenSource.CreateLinkedTokenSource(_stoppingToken, jobCancellationToken))
{
var linkedToken = linkedTokenSource.Token;
_logger.LogInformation($"Starting the scheduler for {job.Name}.");
while (!linkedToken.IsCancellationRequested && job.NextScheduledTime != null)
{
var nextScheduledTime = job.NextScheduledTime.Value;
_logger.LogTrace($"{job.Name} is scheduled to start {nextScheduledTime}");
await Task.WhenAny(Task.Delay(nextScheduledTime - DateTimeOffset.Now, linkedToken)).ConfigureAwait(false);
if (linkedToken.IsCancellationRequested)
{
_logger.LogTrace(_stoppingToken.IsCancellationRequested ?
$"{job.Name} that should have started {nextScheduledTime} has been cancelled because the host is shutting down." :
$"{job.Name} that should have started {nextScheduledTime} has been cancelled because the job is removed.");
break;
}
try
{
var stopwatch = new Stopwatch();
stopwatch.Start();
_logger.LogTrace($"{job.Name} scheduled at {nextScheduledTime} is starting at {DateTimeOffset.Now}.");
var jobTask = job.ExecuteAsync(_stoppingToken);
_logger.LogTrace($"{job.Name} has started.");
await jobTask.ConfigureAwait(false);
stopwatch.Stop();
_logger.LogTrace($"{job.Name} has stopped at {DateTimeOffset.Now}, time elapsed: {stopwatch.Elapsed}.");
}
#pragma warning disable CA1031 // Do not catch general exception types
catch (OperationCanceledException)
{
_logger.LogTrace(_stoppingToken.IsCancellationRequested ?
$"{job.Name} that started at {nextScheduledTime} has been cancelled during execution because the host is shutting down." :
$"{job.Name} that started at {nextScheduledTime} has been cancelled by the job itself.");
break;
}
#pragma warning restore CA1031 // Do not catch general exception types
}
_logger.LogTrace(job.NextScheduledTime == null ?
$"{job.Name} has been removed from the scheduler since there was no more scheduled execution times." :
$"{job.Name} has not been rescheduled since the host is shutting down.");
}
}
