protected void LogProcessingStat(RFEngineProcess process, RFProcessInstruction i, Stopwatch sw, DateTimeOffset startTime)
{
try
{
RFGraphInstance graphInstance = null;
if (i is RFGraphProcessInstruction)
{
return; // these are logged by graph stats
//graphInstance = (i as RFGraphProcessInstruction).Instance;
}
var statsKey = RFEngineStatsKey.Create(_config.KeyDomain, graphInstance);
var statsDocument = _context.Catalog.LoadItem(statsKey, 0) as RFDocument;
if (statsDocument == null)
{
statsDocument = RFDocument.Create(statsKey,
new RFEngineStats
{
GraphInstance = graphInstance,
Stats = new Dictionary <string, RFEngineStat>()
});
}
var stat = new RFEngineStat
{
ProcessName = process.Name,
LastDuration = sw.ElapsedMilliseconds,
LastRun = startTime
};
var statsItem = statsDocument.GetContent <RFEngineStats>();
if (!statsItem.Stats.ContainsKey(process.Name))
{
statsItem.Stats.Add(process.Name, stat);
}
else
{
statsItem.Stats[process.Name] = stat;
}
statsDocument.UpdateTime = DateTimeOffset.Now;
_context.Catalog.SaveItem(statsDocument, true); // don't keep versions
}
catch (Exception ex)
{
Log.Warning(this, "Error saving processing stats for process {0}: {1}", process.Name, ex.Message);
}
}
protected RFProcessingResult ProcessInstruction(RFEngineProcess process, RFProcessInstruction i, IRFProcessingContext processingContext)
{
var result = new RFProcessingResult();
try
{
var sw = Stopwatch.StartNew();
var startTime = DateTimeOffset.Now;
bool completed = false;
try
{
var processorInstance = process.CreateInstance();
if (processorInstance != null)
{
if (_config.MaxRuntime.Ticks > 0)
{
var maxRuntime = TimeSpan.FromTicks(Math.Max(processorInstance.MaxRuntime().Ticks, _config.MaxRuntime.Ticks));
var timerTask = Task.Delay(maxRuntime).ContinueWith(t =>
{
if (!completed)
{
try
{
processorInstance.Cancel();
}
catch (Exception ex)
{
Log.Warning(this, "Exception cancelling process {0}: {1}", process.Name, ex.Message);
}
throw new TimeoutException(String.Format("Cancelling process {0} as it's taken too long (max runtime = {1} seconds).", process.Name, maxRuntime.TotalSeconds));
}
});
}
result = process.RunInstance(processorInstance, i, processingContext);
}
}
catch (Exception ex) // hard exception, or softs should have bene handled by now
{
var message = ex.InnerException?.Message ?? ex.Message;
result.AddMessage(message);
result.IsError = true;
result.ShouldRetry |= (ex is DbException || ex is TimeoutException || ex is RFTransientSystemException || ex?.InnerException is DbException || ex?.InnerException is TimeoutException);
Log.Exception(this, ex, "Exception running process {0}", process.Name);
/*processingContext.UserLog.LogEntry(new RFUserLogEntry
* {
* Action = "Error",
* Area = null,
* Description = String.Format("Error running process {0}: {1}", process.Name, message),
* IsUserAction = false,
* IsWarning = true,
* Processor = process.Name
* });*/
}
completed = true;
LogProcessingStat(process, i, sw, startTime);
Log.Debug(this, String.Format("Engine: process {0} process took {1} ms.", process.Name, sw.ElapsedMilliseconds));
}
catch (Exception ex) // a really bad system exception
{
Log.Exception(this, ex, "Exception processing instruction {0} by process {1}", i, process);
result.AddMessage(ex.Message);
result.IsError = true;
result.ShouldRetry |= (ex is DbException || ex is TimeoutException || ex is RFTransientSystemException || ex?.InnerException is DbException || ex?.InnerException is TimeoutException);
}
return(result);
}
