/// <summary>
/// Handles the specified request. All behaviors will be called first.
/// </summary>
/// <param name="request">The request.</param>
/// <param name="cancellationToken">The cancellation token.</param>
/// <returns></returns>
public override async Task <CommandResponse <TResponse> > Handle(TRequest request, CancellationToken cancellationToken)
{
foreach (var behavior in this.behaviors.Safe())
{
var behaviorResult = await behavior.ExecuteAsync(request).AnyContext();
if (behaviorResult.Cancelled) // abort if this behavior did not succeed
{
// TODO: log reason
return(new CommandResponse <TResponse>(behaviorResult.CancelledReason));
}
}
var commandName = typeof(TRequest).Name.SubstringTill("Command");
this.Logger.LogJournal(LogKeys.AppCommand, $"[{request.Identifier}] handle {commandName}", LogEventPropertyKeys.TrackHandleCommand);
this.Logger.LogTraceEvent(LogKeys.AppCommand, request.Id, commandName, LogTraceEventNames.Command);
using (var timer = new Common.Timer())
{
var result = await this.HandleRequest(request, cancellationToken).AnyContext();
timer.Stop();
this.Logger.LogTraceEvent(LogKeys.AppCommand, request.Id, commandName, LogTraceEventNames.Command, timer.Elapsed);
return(result);
}
}
protected override async Task <HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
{
var correlationId = request.GetCorrelationId();
var requestId = request.GetRequestId();
await this.LogHttpRequest(request, correlationId, requestId);
using (var timer = new Common.Timer())
{
var response = await base.SendAsync(request, cancellationToken).AnyContext();
timer.Stop();
await this.LogHttpResponse(response, requestId, timer.Elapsed);
return(response);
}
}
private async Task ExecuteJobAsync(JobRegistration registration, IJob job, CancellationToken cancellationToken, string[] args = null)
{
if (registration?.Key.IsNullOrEmpty() == false && job != null)
{
try
{
async Task Execute()
{
using (var timer = new Common.Timer())
using (this.logger.BeginScope(new Dictionary <string, object>
{
[LogEventPropertyKeys.CorrelationId] = IdGenerator.Instance.Next
}))
{
// TODO: publish domain event (job started)
var span = IdGenerator.Instance.Next;
this.logger.LogJournal(LogKeys.JobScheduling, $"job started (key={{JobKey}}, id={registration.Identifier}, type={job.GetType().PrettyName()}, isReentrant={registration.IsReentrant}, timeout={registration.Timeout.ToString("c")})", LogEventPropertyKeys.TrackStartJob, args: new[] { registration.Key });
this.logger.LogTraceEvent(LogKeys.JobScheduling, span, registration.Key, LogTraceEventNames.Job);
await job.ExecuteAsync(cancellationToken, args).AnyContext();
await Run.DelayedAsync(new TimeSpan(0, 0, 1), () =>
{
timer.Stop();
this.logger.LogJournal(LogKeys.JobScheduling, $"job finished (key={{JobKey}}, id={registration.Identifier}, type={job.GetType().PrettyName()})", LogEventPropertyKeys.TrackFinishJob, args: new[] { LogKeys.JobScheduling, registration.Key });
this.logger.LogTraceEvent(LogKeys.JobScheduling, span, registration.Key, LogTraceEventNames.Job, timer.Elapsed);
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()})", LogKeys.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()})", 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}}), type={job.GetType().PrettyName()})", LogKeys.JobScheduling, registration.Key);
this.errorHandler?.Invoke(ex.InnerException ?? ex);
}
}
}