/// <summary>
/// The processing thread.
/// </summary>
/// <remarks>
/// This method queries the database for WorkQueue entries to work on, and then uses
/// a thread pool to process the entries.
/// </remarks>
public void Run()
{
// Force the alert to be displayed right away, if it happens
DateTime lastLog = Platform.Time.AddMinutes(-61);
if (!_threadPool.Active)
{
_threadPool.Start();
}
Platform.Log(LogLevel.Info, "Work Queue Processor running...");
while (true)
{
if (_stop)
{
return;
}
bool threadsAvailable = _threadPool.CanQueueItem;
bool memoryAvailable = WorkQueueSettings.Instance.WorkQueueMinimumFreeMemoryMB == 0
||
SystemResources.GetAvailableMemory(SizeUnits.Megabytes) >
WorkQueueSettings.Instance.WorkQueueMinimumFreeMemoryMB;
if (threadsAvailable && memoryAvailable)
{
try
{
Model.WorkQueue queueListItem = GetWorkQueueItem(ServerPlatform.ProcessorId);
if (queueListItem == null)
{
/* No result found, or reach max queue entries for each type */
_terminateEvent.WaitOne(WorkQueueSettings.Instance.WorkQueueQueryDelay, false);
continue;
}
if (!_extensions.ContainsKey(queueListItem.WorkQueueTypeEnum))
{
Platform.Log(LogLevel.Error,
"No extensions loaded for WorkQueue item type: {0}. Failing item.",
queueListItem.WorkQueueTypeEnum);
//Just fail the WorkQueue item, not much else we can do
FailQueueItem(queueListItem, "No plugin to handle WorkQueue type: " + queueListItem.WorkQueueTypeEnum);
continue;
}
try
{
IWorkQueueProcessorFactory factory = _extensions[queueListItem.WorkQueueTypeEnum];
IWorkQueueItemProcessor processor = factory.GetItemProcessor();
// Enqueue the actual processing of the item to the thread pool.
_threadPool.Enqueue(processor, queueListItem, ExecuteProcessor);
}
catch (Exception e)
{
Platform.Log(LogLevel.Error, e, "Unexpected exception creating WorkQueue processor.");
FailQueueItem(queueListItem, "Failure getting WorkQueue processor: " + e.Message);
continue;
}
}
catch (Exception e)
{
// Wait for only 1.5 seconds
Platform.Log(LogLevel.Error, e, "Exception occured when processing WorkQueue item.");
_terminateEvent.WaitOne(3000, false);
}
}
else
{
if ((lastLog.AddMinutes(60) < Platform.Time) && !memoryAvailable)
{
lastLog = Platform.Time;
Platform.Log(LogLevel.Error, "Unable to process WorkQueue entries, Minimum memory not available, minimum MB required: {0}, current MB available:{1}",
WorkQueueSettings.Instance.WorkQueueMinimumFreeMemoryMB,
SystemResources.GetAvailableMemory(SizeUnits.Megabytes));
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Critical, "WorkQueue", AlertTypeCodes.NoResources,
null, TimeSpan.Zero,
"Unable to process WorkQueue entries, Minimum memory not available, minimum MB required: {0}, current MB available:{1}",
WorkQueueSettings.Instance.WorkQueueMinimumFreeMemoryMB,
SystemResources.GetAvailableMemory(SizeUnits.Megabytes));
}
// wait for new opening in the pool or termination
WaitHandle.WaitAny(new WaitHandle[] { _threadStop, _terminateEvent }, 3000, false);
_threadStop.Reset();
}
}
}
/// <summary>
/// Do the insertion of the AutoRoute.
/// </summary>
protected override void OnExecute(CommandProcessor theProcessor, IUpdateContext updateContext)
{
var deviceSelectCriteria = new DeviceSelectCriteria();
deviceSelectCriteria.AeTitle.EqualTo(_deviceAe);
deviceSelectCriteria.ServerPartitionKey.EqualTo(_context.ServerPartitionKey);
var selectDevice = updateContext.GetBroker <IDeviceEntityBroker>();
var dev = selectDevice.FindOne(deviceSelectCriteria);
if (dev == null)
{
Platform.Log(LogLevel.Warn,
"Device '{0}' on partition {1} not in database for autoroute request! Ignoring request.", _deviceAe,
_context.ServerPartition.AeTitle);
ServerPlatform.Alert(
AlertCategory.Application, AlertLevel.Warning,
SR.AlertComponentAutorouteRule, AlertTypeCodes.UnableToProcess, null, TimeSpan.FromMinutes(5),
SR.AlertAutoRouteUnknownDestination, _deviceAe, _context.ServerPartition.AeTitle);
return;
}
if (!dev.AllowAutoRoute)
{
Platform.Log(LogLevel.Warn,
"Study Auto-route attempted to device {0} on partition {1} with autoroute support disabled. Ignoring request.",
dev.AeTitle, _context.ServerPartition.AeTitle);
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Warning, SR.AlertComponentAutorouteRule,
AlertTypeCodes.UnableToProcess, null, TimeSpan.FromMinutes(5),
SR.AlertAutoRouteDestinationAEDisabled, dev.AeTitle, _context.ServerPartition.AeTitle);
return;
}
if (_qcStatus != null)
{
var studyBroker = updateContext.GetBroker <IStudyEntityBroker>();
var studySelect = new StudySelectCriteria();
studySelect.StudyStorageKey.EqualTo(_context.StudyLocationKey);
studySelect.ServerPartitionKey.EqualTo(_context.ServerPartitionKey);
var study = studyBroker.FindOne(studySelect);
if (!study.QCStatusEnum.Equals(_qcStatus))
{
Platform.Log(LogLevel.Debug,
"Ignoring Auto-route where the QCStatusEnum status must be {0}, but database has {1} for study {2}",
_qcStatus.Description, study.QCStatusEnum.Description, study.StudyInstanceUid);
return;
}
}
var parms = new InsertWorkQueueParameters
{
WorkQueueTypeEnum = WorkQueueTypeEnum.StudyAutoRoute,
ScheduledTime = _scheduledTime.HasValue
? _scheduledTime.Value
: Platform.Time.AddSeconds(30),
StudyStorageKey = _context.StudyLocationKey,
ServerPartitionKey = _context.ServerPartitionKey,
DeviceKey = dev.GetKey()
};
var broker = updateContext.GetBroker <IInsertWorkQueue>();
if (broker.FindOne(parms) == null)
{
throw new ApplicationException("InsertWorkQueue for Study Auto-Route failed");
}
}
/// <summary>
/// Updates the 'State' of the filesystem associated with the 'FilesystemDelete' <see cref="ServiceLock"/> item
/// </summary>
/// <param name="item"></param>
/// <param name="fs"></param>
private static void UpdateState(Model.ServiceLock item, ServerFilesystemInfo fs)
{
FilesystemState state = null;
if (item.State != null && item.State.DocumentElement != null)
{
//load from datatabase
state = XmlUtils.Deserialize <FilesystemState>(item.State.DocumentElement);
}
if (state == null)
{
state = new FilesystemState();
}
if (fs.AboveHighWatermark)
{
// we don't want to generate alert if the filesystem is offline or not accessible.
if (fs.Online && (fs.Readable || fs.Writeable))
{
TimeSpan ALERT_INTERVAL = TimeSpan.FromMinutes(ServiceLockSettings.Default.HighWatermarkAlertInterval);
if (state.AboveHighWatermarkTimestamp == null)
{
state.AboveHighWatermarkTimestamp = Platform.Time;
}
TimeSpan elapse = (state.LastHighWatermarkAlertTimestamp != null) ? Platform.Time - state.LastHighWatermarkAlertTimestamp.Value : Platform.Time - state.AboveHighWatermarkTimestamp.Value;
if (elapse.Duration() >= ALERT_INTERVAL)
{
ServerPlatform.Alert(AlertCategory.System, AlertLevel.Warning, "Filesystem",
AlertTypeCodes.LowResources, null, TimeSpan.Zero,
SR.AlertFilesystemAboveHW,
fs.Filesystem.Description,
TimeSpanFormatter.Format(Platform.Time - state.AboveHighWatermarkTimestamp.Value, true));
state.LastHighWatermarkAlertTimestamp = Platform.Time;
}
}
else
{
state.AboveHighWatermarkTimestamp = null;
state.LastHighWatermarkAlertTimestamp = null;
}
}
else
{
state.AboveHighWatermarkTimestamp = null;
state.LastHighWatermarkAlertTimestamp = null;
}
XmlDocument stateXml = new XmlDocument();
stateXml.AppendChild(stateXml.ImportNode(XmlUtils.Serialize(state), true));
IPersistentStore store = PersistentStoreRegistry.GetDefaultStore();
using (IUpdateContext ctx = store.OpenUpdateContext(UpdateContextSyncMode.Flush))
{
ServiceLockUpdateColumns columns = new ServiceLockUpdateColumns();
columns.State = stateXml;
IServiceLockEntityBroker broker = ctx.GetBroker <IServiceLockEntityBroker>();
broker.Update(item.GetKey(), columns);
ctx.Commit();
}
}
/// <summary>
/// Migrates the study to new tier
/// </summary>
/// <param name="storage"></param>
/// <param name="newFilesystem"></param>
private void DoMigrateStudy(StudyStorageLocation storage, ServerFilesystemInfo newFilesystem)
{
Platform.CheckForNullReference(storage, "storage");
Platform.CheckForNullReference(newFilesystem, "newFilesystem");
TierMigrationStatistics stat = new TierMigrationStatistics {
StudyInstanceUid = storage.StudyInstanceUid
};
stat.ProcessSpeed.Start();
StudyXml studyXml = storage.LoadStudyXml();
stat.StudySize = (ulong)studyXml.GetStudySize();
Platform.Log(LogLevel.Info, "About to migrate study {0} from {1} to {2}",
storage.StudyInstanceUid, storage.FilesystemTierEnum, newFilesystem.Filesystem.Description);
string newPath = Path.Combine(newFilesystem.Filesystem.FilesystemPath, storage.PartitionFolder);
DateTime startTime = Platform.Time;
DateTime lastLog = Platform.Time;
int fileCounter = 0;
ulong bytesCopied = 0;
long instanceCountInXml = studyXml.NumberOfStudyRelatedInstances;
using (ServerCommandProcessor processor = new ServerCommandProcessor("Migrate Study"))
{
TierMigrationContext context = new TierMigrationContext
{
OriginalStudyLocation = storage,
Destination = newFilesystem
};
string origFolder = context.OriginalStudyLocation.GetStudyPath();
processor.AddCommand(new CreateDirectoryCommand(newPath));
newPath = Path.Combine(newPath, context.OriginalStudyLocation.StudyFolder);
processor.AddCommand(new CreateDirectoryCommand(newPath));
newPath = Path.Combine(newPath, context.OriginalStudyLocation.StudyInstanceUid);
// don't create this directory so that it won't be backed up by MoveDirectoryCommand
CopyDirectoryCommand copyDirCommand = new CopyDirectoryCommand(origFolder, newPath,
delegate(string path)
{
// Update the progress. This is useful if the migration takes long time to complete.
FileInfo file = new FileInfo(path);
bytesCopied += (ulong)file.Length;
fileCounter++;
if (file.Extension != null && file.Extension.Equals(ServerPlatform.DicomFileExtension, StringComparison.InvariantCultureIgnoreCase))
{
TimeSpan elapsed = Platform.Time - lastLog;
TimeSpan totalElapsed = Platform.Time - startTime;
double speedInMBPerSecond = 0;
if (totalElapsed.TotalSeconds > 0)
{
speedInMBPerSecond = (bytesCopied / 1024f / 1024f) / totalElapsed.TotalSeconds;
}
if (elapsed > TimeSpan.FromSeconds(WorkQueueSettings.Instance.TierMigrationProgressUpdateInSeconds))
{
#region Log Progress
StringBuilder stats = new StringBuilder();
if (instanceCountInXml != 0)
{
float pct = (float)fileCounter / instanceCountInXml;
stats.AppendFormat("{0} files moved [{1:0.0}MB] since {2} ({3:0}% completed). Speed={4:0.00}MB/s",
fileCounter, bytesCopied / 1024f / 1024f, startTime, pct * 100, speedInMBPerSecond);
}
else
{
stats.AppendFormat("{0} files moved [{1:0.0}MB] since {2}. Speed={3:0.00}MB/s",
fileCounter, bytesCopied / 1024f / 1024f, startTime, speedInMBPerSecond);
}
Platform.Log(LogLevel.Info, "Tier migration for study {0}: {1}", storage.StudyInstanceUid, stats.ToString());
try
{
using (IUpdateContext ctx = PersistentStoreRegistry.GetDefaultStore().OpenUpdateContext(UpdateContextSyncMode.Flush))
{
IWorkQueueEntityBroker broker = ctx.GetBroker <IWorkQueueEntityBroker>();
WorkQueueUpdateColumns parameters = new WorkQueueUpdateColumns
{
FailureDescription = stats.ToString()
};
broker.Update(WorkQueueItem.GetKey(), parameters);
ctx.Commit();
}
}
catch
{
// can't log the progress so far... just ignore it
}
finally
{
lastLog = DateTime.Now;
}
#endregion
}
}
});
processor.AddCommand(copyDirCommand);
DeleteDirectoryCommand delDirCommand = new DeleteDirectoryCommand(origFolder, false)
{
RequiresRollback = false
};
processor.AddCommand(delDirCommand);
TierMigrateDatabaseUpdateCommand updateDbCommand = new TierMigrateDatabaseUpdateCommand(context);
processor.AddCommand(updateDbCommand);
Platform.Log(LogLevel.Info, "Start migrating study {0}.. expecting {1} to be moved", storage.StudyInstanceUid, ByteCountFormatter.Format(stat.StudySize));
if (!processor.Execute())
{
if (processor.FailureException != null)
{
throw processor.FailureException;
}
throw new ApplicationException(processor.FailureReason);
}
stat.DBUpdate = updateDbCommand.Statistics;
stat.CopyFiles = copyDirCommand.CopySpeed;
stat.DeleteDirTime = delDirCommand.Statistics;
}
stat.ProcessSpeed.SetData(bytesCopied);
stat.ProcessSpeed.End();
Platform.Log(LogLevel.Info, "Successfully migrated study {0} from {1} to {2} in {3} [ {4} files, {5} @ {6}, DB Update={7}, Remove Dir={8}]",
storage.StudyInstanceUid,
storage.FilesystemTierEnum,
newFilesystem.Filesystem.FilesystemTierEnum,
TimeSpanFormatter.Format(stat.ProcessSpeed.ElapsedTime),
fileCounter,
ByteCountFormatter.Format(bytesCopied),
stat.CopyFiles.FormattedValue,
stat.DBUpdate.FormattedValue,
stat.DeleteDirTime.FormattedValue);
string originalPath = storage.GetStudyPath();
if (Directory.Exists(storage.GetStudyPath()))
{
Platform.Log(LogLevel.Info, "Original study folder could not be deleted. It must be cleaned up manually: {0}", originalPath);
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Warning, WorkQueueItem.WorkQueueTypeEnum.ToString(), 1000, GetWorkQueueContextData(WorkQueueItem), TimeSpan.Zero,
"Study has been migrated to a new tier. Original study folder must be cleaned up manually: {0}", originalPath);
}
UpdateAverageStatistics(stat);
}
/// <summary>
/// The processing thread.
/// </summary>
/// <remarks>
/// This method queries the database for ServiceLock entries to work on, and then uses
/// a thread pool to process the entries.
/// </remarks>
public void Run()
{
// Start the thread pool
if (!_threadPool.Active)
{
_threadPool.Start();
}
// Reset any queue items related to this service that are have the Lock bit set.
try
{
ResetLocked();
}
catch (Exception e)
{
Platform.Log(LogLevel.Fatal, e,
"Unable to reset ServiceLock items on startup. There may be ServiceLock items orphaned in the queue.");
}
Platform.Log(LogLevel.Info, "ServiceLock Processor is running");
while (true)
{
try
{
if (_threadPool.CanQueueItem)
{
Model.ServiceLock queueListItem;
using (IUpdateContext updateContext = _store.OpenUpdateContext(UpdateContextSyncMode.Flush))
{
IQueryServiceLock select = updateContext.GetBroker <IQueryServiceLock>();
ServiceLockQueryParameters parms = new ServiceLockQueryParameters();
parms.ProcessorId = ServerPlatform.ProcessorId;
queueListItem = select.FindOne(parms);
updateContext.Commit();
}
if (queueListItem == null)
{
WaitHandle.WaitAny(new WaitHandle[] { _terminationEvent, _threadStop }, TimeSpan.FromSeconds(30), false);
_threadStop.Reset();
}
else
{
if (!_extensions.ContainsKey(queueListItem.ServiceLockTypeEnum))
{
Platform.Log(LogLevel.Error,
"No extensions loaded for ServiceLockTypeEnum item type: {0}. Failing item.",
queueListItem.ServiceLockTypeEnum);
//Just fail the ServiceLock item, not much else we can do
ResetServiceLock(queueListItem);
continue;
}
IServiceLockProcessorFactory factory = _extensions[queueListItem.ServiceLockTypeEnum];
IServiceLockItemProcessor processor;
try
{
processor = factory.GetItemProcessor();
}
catch (Exception e)
{
Platform.Log(LogLevel.Error, e, "Unexpected exception creating ServiceLock processor.");
ResetServiceLock(queueListItem);
continue;
}
_threadPool.Enqueue(processor, queueListItem, delegate(IServiceLockItemProcessor queueProcessor, Model.ServiceLock queueItem)
{
try
{
queueProcessor.Process(queueItem);
}
catch (Exception e)
{
Platform.Log(LogLevel.Error, e,
"Unexpected exception when processing ServiceLock item of type {0}. Failing Queue item. (GUID: {1})",
queueItem.ServiceLockTypeEnum,
queueItem.GetKey());
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Error, "ServiceLockProcessor",
AlertTypeCodes.UnableToProcess,
null, TimeSpan.Zero,
"Exception thrown when processing {0} ServiceLock item : {1}",
queueItem.ServiceLockTypeEnum.Description, e.Message);
ResetServiceLock(queueItem);
}
// Cleanup the processor
queueProcessor.Dispose();
// Signal the thread to come out of sleep mode
_threadStop.Set();
});
}
}
else
{
// Wait for only 5 seconds when the thread pool is all in use.
WaitHandle.WaitAny(new WaitHandle[] { _terminationEvent, _threadStop }, TimeSpan.FromSeconds(5), false);
_threadStop.Reset();
}
}
catch (Exception ex)
{
Platform.Log(LogLevel.Error, ex, "Exception has occurred : {0}. Retry later.", ex.Message);
WaitHandle.WaitAny(new WaitHandle[] { _terminationEvent, _threadStop }, TimeSpan.FromSeconds(5), false);
_threadStop.Reset();
}
if (_stop)
{
return;
}
}
}
protected List <FileInfo> LoadSopFiles(DirectoryInfo studyDir, bool cleanup)
{
List <string> filesDeleted = new List <string>();
List <FileInfo> fileList = new List <FileInfo>();
FileProcessor.Process(studyDir.FullName, "*.*",
delegate(string filePath, out bool cancel)
{
cancel = CancelPending;
if (cancel)
{
return;
}
FileInfo file = new FileInfo(filePath);
// if the file is located in a "deleted" directory then skip it
if (file.DirectoryName != null)
{
if (file.DirectoryName.EndsWith("Deleted", StringComparison.InvariantCultureIgnoreCase))
{
return;
}
}
if (file.Extension.Equals(ServerPlatform.DicomFileExtension,
StringComparison.InvariantCultureIgnoreCase))
{
fileList.Add(file);
}
else
{
if (file.Extension.Equals(".xml", StringComparison.InvariantCultureIgnoreCase) ||
file.Extension.Equals(".gz", StringComparison.InvariantCultureIgnoreCase))
{
// is header file
}
else
{
// TODO: Should we be smarter when dealing with left-over files?
// For eg, if we encounter 123.dcm_temp that appears to be
// a complete version of a corrupted 123.dcm, shouldn't we replace
// 123.dcm with the 123.dcm_temp instead of deleting 123.dcm_temp?
// Delete it
if (cleanup)
{
file.Delete();
filesDeleted.Add(filePath);
}
}
}
},
true);
if (filesDeleted.Count > 0)
{
// Raise alerts. Each alert lists 10 files that were deleted.
int count = 0;
StringBuilder msg = new StringBuilder();
foreach (string file in filesDeleted)
{
count++;
msg.AppendLine(String.Format("{0};", file));
if (count % 10 == 0 || count == filesDeleted.Count)
{
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Warning, "Reinventory", 10000, null, TimeSpan.Zero, "Following files were removed:{0}", msg.ToString());
msg = new StringBuilder();
}
}
}
return(fileList);
}
private int ProcessFile(string filePath)
{
int importedSopCount = 0;
bool isDicomFile = false;
bool skipped = false;
FileInfo fileInfo = new FileInfo(filePath);
if (fileInfo.Exists)
{
DicomFile file;
try
{
file = new DicomFile(filePath);
file.Load();
isDicomFile = true;
string studyInstanceUid;
if (file.DataSet[DicomTags.StudyInstanceUid].TryGetString(0, out studyInstanceUid))
{
skipped = _skippedStudies.Contains(studyInstanceUid);
if (!skipped)
{
InitializeImporter();
try
{
DicomProcessingResult result = _importer.Import(file);
if (result.Successful)
{
if (result.Duplicate)
{
// was imported but is duplicate
}
else
{
importedSopCount = 1;
Platform.Log(LogLevel.Info, "Imported SOP {0} to {1}", result.SopInstanceUid, _parms.PartitionAE);
ProgressChangedEventArgs progress = new ProgressChangedEventArgs(100, result.SopInstanceUid);
// Fire the imported event.
SopImportedEventArgs args = new SopImportedEventArgs
{
StudyInstanceUid = result.StudyInstanceUid,
SeriesInstanceUid = result.SeriesInstanceUid,
SopInstanceUid = result.SopInstanceUid
};
EventsHelper.Fire(_sopImportedHandlers, this, args);
OnProgressChanged(progress);
}
}
else
{
if (result.DicomStatus == DicomStatuses.StorageStorageOutOfResources)
{
if (result.RestoreRequested)
{
EventsHelper.Fire(_restoreTriggerHandlers, this, null);
}
Platform.Log(LogLevel.Info, "Images for study {0} cannot be imported at this time because: {1}", result.StudyInstanceUid, result.ErrorMessage);
_skippedStudies.Add(result.StudyInstanceUid);
skipped = true;
}
else
{
Platform.Log(LogLevel.Warn, "Failed to import {0} to {1} : {2}", filePath, _parms.PartitionAE, result.ErrorMessage);
}
}
}
catch (DicomDataException ex)
{
// skip to next file, this file will be deleted
Platform.Log(LogLevel.Warn, ex, "Failed to import {0} to {1}: {2}", filePath, _parms.PartitionAE, ex.Message);
skipped = true;
}
}
}
else
{
throw new ApplicationException("Sop does not contains Study Instance Uid tag");
}
}
catch (Exception ex)
{
Platform.Log(LogLevel.Error, ex);
}
finally
{
try
{
if (importedSopCount > 0)
{
DeleteFile(fileInfo);
}
else if (!isDicomFile)
{
DeleteFile(fileInfo);
}
else
{
//is dicom file but could not be imported.
if (!skipped)
{
DeleteFile(fileInfo);
}
}
}
catch (IOException ex)
{
Platform.Log(LogLevel.Error, ex, "Unable to delete file after it has been imported: {0}", fileInfo.FullName);
// Raise alert because this file is stuck in the incoming folder and becomes a duplicate when it is imported again later on.
// Depending on the duplicate policy, SIQ may be filled with many duplicate entries.
ServerPlatform.Alert(AlertCategory.Application, AlertLevel.Critical, "File Importer", -1, null, TimeSpan.Zero,
"The following file has been imported but could not be removed : {0}.\nError: {1}",
fileInfo.FullName, ex.Message);
}
}
}
return(importedSopCount);
}
