/// <summary> /// Process the <see cref="ServiceLock"/> item. /// </summary> /// <param name="item"></param> protected override void OnProcess(Model.ServiceLock item) { LoadRulesEngine(); ServerFilesystemInfo info = FilesystemMonitor.Instance.GetFilesystemInfo(item.FilesystemKey); _stats.StudyRate.Start(); _stats.Filesystem = info.Filesystem.Description; Platform.Log(LogLevel.Info, "Starting reprocess of filesystem: {0}", info.Filesystem.Description); ReprocessFilesystem(info.Filesystem); Platform.Log(LogLevel.Info, "Completed reprocess of filesystem: {0}", info.Filesystem.Description); _stats.StudyRate.SetData(_stats.NumStudies); _stats.StudyRate.End(); StatisticsLogger.Log(LogLevel.Info, _stats); item.ScheduledTime = item.ScheduledTime.AddDays(1); if (CancelPending) { Platform.Log(LogLevel.Info, "Filesystem Reprocess of {0} has been canceled, rescheduling. Entire filesystem will be reprocessed.", info.Filesystem.Description); UnlockServiceLock(item, true, Platform.Time.AddMinutes(1)); } else { UnlockServiceLock(item, false, Platform.Time.AddDays(1)); } }
private static void HandleRequest(HttpListenerContext context) { WADORequestProcessorStatistics statistics = new WADORequestProcessorStatistics("Image Streaming"); statistics.TotalProcessTime.Start(); if (Platform.IsLogLevelEnabled(LogLevel.Debug)) { //Don't hold up this thread for logging. Task.Factory.StartNew(() => LogRequest(context)); } try { using (WADORequestTypeHandlerManager handlerManager = new WADORequestTypeHandlerManager()) { string requestType = context.Request.QueryString["requestType"]; IWADORequestTypeHandler typeHandler = handlerManager.GetHandler(requestType); WADORequestTypeHandlerContext ctx = new WADORequestTypeHandlerContext { HttpContext = context, ServerAE = UriHelper.GetServerAE(context) }; using (WADOResponse response = typeHandler.Process(ctx)) { if (response != null) { statistics.TransmissionSpeed.Start(); SendWADOResponse(response, context); statistics.TransmissionSpeed.End(); if (response.Output != null) { statistics.TransmissionSpeed.SetData(response.Output.Length); } } } } } catch (MimeTypeProcessorError error) { SendError(error.HttpError, context); } statistics.TotalProcessTime.End(); //Seems like something you'd only want to log if there was a problem. if (Platform.IsLogLevelEnabled(LogLevel.Debug)) { //Don't hold up this thread for logging. Task.Factory.StartNew(() => StatisticsLogger.Log(LogLevel.Debug, statistics)); } }
protected override void OnProcessItemEnd(Model.WorkQueue item) { Platform.CheckForNullReference(item, "item"); base.OnProcessItemEnd(item); Statistics.UidsLoadTime.Add(UidsLoadTime); Statistics.StorageLocationLoadTime.Add(StorageLocationLoadTime); Statistics.StudyXmlLoadTime.Add(StudyXmlLoadTime); Statistics.DBUpdateTime.Add(DBUpdateTime); if (Statistics.NumInstances > 0) { Statistics.CalculateAverage(); StatisticsLogger.Log(LogLevel.Info, false, Statistics); } }
private static void UpdateAverageStatistics(TierMigrationStatistics stat) { lock (_statisticsLock) { _average.AverageProcessSpeed.AddSample(stat.ProcessSpeed); _average.AverageStudySize.AddSample(stat.StudySize); _average.AverageStudySize.AddSample(stat.ProcessSpeed); _average.AverageFileMoveTime.AddSample(stat.CopyFiles); _average.AverageDBUpdateTime.AddSample(stat.DBUpdate); _studiesMigratedCount++; if (_studiesMigratedCount % 5 == 0) { StatisticsLogger.Log(LogLevel.Info, _average); _average = new TierMigrationAverageStatistics(); } } }
private static void HandleRequest(HttpListenerContext context) { WADORequestProcessorStatistics statistics = new WADORequestProcessorStatistics("Image Streaming"); statistics.TotalProcessTime.Start(); LogRequest(context); try { using (WADORequestTypeHandlerManager handlerManager = new WADORequestTypeHandlerManager()) { string requestType = context.Request.QueryString["requestType"]; IWADORequestTypeHandler typeHandler = handlerManager.GetHandler(requestType); WADORequestTypeHandlerContext ctx = new WADORequestTypeHandlerContext { HttpContext = context, ServerAE = UriHelper.GetServerAE(context) }; using (WADOResponse response = typeHandler.Process(ctx)) { if (response != null) { statistics.TransmissionSpeed.Start(); SendWADOResponse(response, context); statistics.TransmissionSpeed.End(); if (response.Output != null) { statistics.TransmissionSpeed.SetData(response.Output.Length); } } } } } catch (MimeTypeProcessorError error) { SendError(error.HttpError, context); } statistics.TotalProcessTime.End(); StatisticsLogger.Log(LogLevel.Debug, statistics); }
/// <summary> /// Event handler called when an association has been released. /// </summary> /// <param name="assoc">The association</param> protected void OnAssociationReleased(AssociationParameters assoc) { if (_assocStats == null) { return; } // update the association statistics _assocStats.IncomingBytes = assoc.TotalBytesRead; _assocStats.OutgoingBytes = assoc.TotalBytesSent; // signal stop recording.. the statistic object will fill out whatever // it needs at this point based on what we have set _assocStats.End(); if (_logInformation) { StatisticsLogger.Log(LogLevel.Info, _assocStats); } }
/// <summary> /// Process study migration candidates retrieved from the <see cref="Model.FilesystemQueue"/> table /// </summary> /// <param name="candidateList">The list of candidate studies for deleting.</param> private void ProcessStudyMigrateCandidates(IList <FilesystemQueue> candidateList) { Platform.CheckForNullReference(candidateList, "candidateList"); if (candidateList.Count > 0) { Platform.Log(LogLevel.Debug, "Scheduling tier-migration for {0} eligible studies...", candidateList.Count); } FilesystemProcessStatistics summaryStats = new FilesystemProcessStatistics("FilesystemTierMigrateInsert"); foreach (FilesystemQueue queueItem in candidateList) { if (_bytesToRemove < 0 || CancelPending) { Platform.Log(LogLevel.Debug, "Estimated disk space has been reached."); break; } StudyProcessStatistics stats = new StudyProcessStatistics("TierMigrateStudy"); stats.TotalTime.Start(); stats.StudyStorageTime.Start(); // First, get the StudyStorage locations for the study, and calculate the disk usage. StudyStorageLocation location; if (!FilesystemMonitor.Instance.GetWritableStudyStorageLocation(queueItem.StudyStorageKey, out location)) { continue; } stats.StudyStorageTime.End(); stats.CalculateDirectorySizeTime.Start(); // Get the disk usage float studySize = EstimateFolderSizeFromStudyXml(location); stats.CalculateDirectorySizeTime.End(); stats.DirectorySize = (ulong)studySize; stats.DbUpdateTime.Start(); using ( IUpdateContext update = PersistentStoreRegistry.GetDefaultStore().OpenUpdateContext(UpdateContextSyncMode.Flush)) { ILockStudy lockstudy = update.GetBroker <ILockStudy>(); LockStudyParameters lockParms = new LockStudyParameters { StudyStorageKey = location.Key, QueueStudyStateEnum = QueueStudyStateEnum.MigrationScheduled }; if (!lockstudy.Execute(lockParms) || !lockParms.Successful) { Platform.Log(LogLevel.Warn, "Unable to lock study for inserting Tier Migration. Reason:{0}. Skipping study ({1})", lockParms.FailureReason, location.StudyInstanceUid); continue; } IInsertWorkQueueFromFilesystemQueue broker = update.GetBroker <IInsertWorkQueueFromFilesystemQueue>(); InsertWorkQueueFromFilesystemQueueParameters insertParms = new InsertWorkQueueFromFilesystemQueueParameters { StudyStorageKey = location.GetKey(), ServerPartitionKey = location.ServerPartitionKey, ScheduledTime = _scheduledTime, DeleteFilesystemQueue = true, WorkQueueTypeEnum = WorkQueueTypeEnum.MigrateStudy, FilesystemQueueTypeEnum = FilesystemQueueTypeEnum.TierMigrate }; Platform.Log(LogLevel.Debug, "Scheduling tier-migration for study {0} from {1} at {2}...", location.StudyInstanceUid, location.FilesystemTierEnum, _scheduledTime); WorkQueue insertItem = broker.FindOne(insertParms); if (insertItem == null) { Platform.Log(LogLevel.Error, "Unexpected problem inserting 'MigrateStudy' record into WorkQueue for Study {0}", location.StudyInstanceUid); } else { update.Commit(); _bytesToRemove -= studySize; _studiesMigrated++; // spread out the scheduled migration entries based on the size // assuming that the larger the study the longer it will take to migrate // The assumed migration speed is arbitarily chosen. double migrationSpeed = ServiceLockSettings.Default.TierMigrationSpeed * 1024 * 1024; // MB / sec TimeSpan estMigrateTime = TimeSpan.FromSeconds(studySize / migrationSpeed); _scheduledTime = _scheduledTime.Add(estMigrateTime); } } stats.DbUpdateTime.End(); stats.TotalTime.End(); summaryStats.AddSubStats(stats); StatisticsLogger.Log(LogLevel.Debug, stats); } summaryStats.CalculateAverage(); StatisticsLogger.Log(LogLevel.Info, false, summaryStats); }
/// <summary> /// Process StudyPurge <see cref="FilesystemQueue"/> entries. /// </summary> /// <param name="candidateList">The list of candidates for purging</param> private void ProcessStudyPurgeCandidates(IList <FilesystemQueue> candidateList) { if (candidateList.Count > 0) { Platform.Log(LogLevel.Debug, "Scheduling purge study for {0} eligible studies...", candidateList.Count); } FilesystemProcessStatistics summaryStats = new FilesystemProcessStatistics("FilesystemPurgeInsert"); foreach (FilesystemQueue queueItem in candidateList) { if (_bytesToRemove < 0 || CancelPending) { break; } StudyProcessStatistics stats = new StudyProcessStatistics("PurgeStudy"); stats.TotalTime.Start(); stats.StudyStorageTime.Start(); // First, get the StudyStorage locations for the study, and calculate the disk usage. StudyStorageLocation location; if (!FilesystemMonitor.Instance.GetWritableStudyStorageLocation(queueItem.StudyStorageKey, out location)) { continue; } stats.StudyStorageTime.End(); stats.CalculateDirectorySizeTime.Start(); // Get the disk usage float studySize = EstimateFolderSizeFromStudyXml(location); stats.CalculateDirectorySizeTime.End(); stats.DirectorySize = (ulong)studySize; stats.DbUpdateTime.Start(); // Update the DB using ( IUpdateContext update = PersistentStoreRegistry.GetDefaultStore().OpenUpdateContext(UpdateContextSyncMode.Flush)) { ILockStudy lockstudy = update.GetBroker <ILockStudy>(); LockStudyParameters lockParms = new LockStudyParameters(); lockParms.StudyStorageKey = location.Key; lockParms.QueueStudyStateEnum = QueueStudyStateEnum.PurgeScheduled; if (!lockstudy.Execute(lockParms) || !lockParms.Successful) { Platform.Log(LogLevel.Warn, "Unable to lock study for inserting Study Purge, skipping study ({0}", location.StudyInstanceUid); continue; } IInsertWorkQueueFromFilesystemQueue insertBroker = update.GetBroker <IInsertWorkQueueFromFilesystemQueue>(); InsertWorkQueueFromFilesystemQueueParameters insertParms = new InsertWorkQueueFromFilesystemQueueParameters(); insertParms.StudyStorageKey = location.GetKey(); insertParms.ServerPartitionKey = location.ServerPartitionKey; insertParms.ScheduledTime = _scheduledTime; insertParms.DeleteFilesystemQueue = true; insertParms.WorkQueueTypeEnum = WorkQueueTypeEnum.PurgeStudy; insertParms.FilesystemQueueTypeEnum = FilesystemQueueTypeEnum.PurgeStudy; WorkQueue insertItem = insertBroker.FindOne(insertParms); if (insertItem == null) { Platform.Log(LogLevel.Error, "Unexpected problem inserting 'PurgeStudy' record into WorkQueue for Study {0}", location.StudyInstanceUid); } else { update.Commit(); _bytesToRemove -= studySize; _studiesPurged++; _scheduledTime = _scheduledTime.AddSeconds(2); } } stats.DbUpdateTime.End(); stats.TotalTime.End(); summaryStats.AddSubStats(stats); StatisticsLogger.Log(LogLevel.Debug, stats); } summaryStats.CalculateAverage(); StatisticsLogger.Log(LogLevel.Info, false, summaryStats); }
public Stream GetStudyHeader(string callingAETitle, HeaderStreamingParameters parameters) { ConnectionMonitor.GetMonitor(OperationContext.Current.Host).AddContext(OperationContext.Current); HeaderStreamingStatistics stats = new HeaderStreamingStatistics(); stats.ProcessTime.Start(); HeaderLoader loader = null; try { Platform.CheckForEmptyString(callingAETitle, "callingAETitle"); Platform.CheckForNullReference(parameters, "parameters"); Platform.CheckForEmptyString(parameters.ReferenceID, "parameters.ReferenceID"); Platform.CheckForEmptyString(parameters.ServerAETitle, "parameters.ServerAETitle"); Platform.CheckForEmptyString(parameters.StudyInstanceUID, "parameters.StudyInstanceUID"); Platform.Log(LogLevel.Debug, "Received request from {0}. Ref # {1} ", callingAETitle, parameters.ReferenceID); HeaderStreamingContext context = new HeaderStreamingContext(); context.ServiceInstanceID = ID; context.CallerAE = callingAETitle; context.Parameters = parameters; // TODO: perform permission check on callingAETitle loader = new HeaderLoader(context); if (!parameters.IgnoreInUse) { if (!loader.StudyLocation.CanBeUsedForDiagnostics()) { throw new StudyAccessException(SR.FaultFaultStudyTemporarilyNotAccessible, loader.StudyLocation.QueueStudyStateEnum, null); } } Stream stream = loader.Load(); if (stream == null) { throw new FaultException(loader.FaultDescription); } Platform.Log(LogLevel.Debug, "Response sent to {0}. Ref # {1} ", callingAETitle, parameters.ReferenceID); return(stream); } catch (ArgumentException e) { throw new FaultException(e.Message); } catch (StudyNotFoundException) { throw new FaultException <StudyNotFoundFault>( new StudyNotFoundFault(), String.Format(SR.FaultNotExists, parameters.StudyInstanceUID, parameters.ServerAETitle)); } catch (StudyIsNearlineException e) { throw new FaultException <StudyIsNearlineFault>( new StudyIsNearlineFault() { IsStudyBeingRestored = e.RestoreRequested }, String.Format(SR.FaultStudyIsNearline, parameters.StudyInstanceUID)); } catch (StudyAccessException e) { if (e.InnerException != null) { if (e.InnerException is FileNotFoundException) { throw new FaultException <StudyIsInUseFault>( new StudyIsInUseFault(e.StudyState.Description), String.Format(SR.FaultFaultStudyTemporarilyNotAccessible, parameters.StudyInstanceUID, e.StudyState)); } } throw new FaultException <StudyIsInUseFault>( new StudyIsInUseFault(e.StudyState.Description), String.Format(SR.FaultFaultStudyTemporarilyNotAccessible, parameters.StudyInstanceUID, e.StudyState)); } catch (FilesystemNotReadableException e) { //interpret as generic fault throw new FaultException(e.Message); } catch (FileNotFoundException e) { // OOPS.. the header is missing Platform.Log(LogLevel.Error, e, "Unable to process study header request from {0}", callingAETitle); throw new FaultException(SR.FaultHeaderIsNotAvailable); } catch (Exception e) { if (!(e is FaultException)) { Platform.Log(LogLevel.Error, e, "Unable to process study header request from {0}", callingAETitle); } throw new FaultException(e.Message); } finally { stats.ProcessTime.End(); if (loader != null && Settings.Default.LogStatistics) { stats.AddField("StudyInstanceUid", parameters.StudyInstanceUID); stats.AddSubStats(loader.Statistics); StatisticsLogger.Log(LogLevel.Info, stats); } } }
/// <summary> /// Perform the edit. /// </summary> /// <param name="actionXml">A serialized XML representation of <see cref="SetTagCommand"/> objects</param> /// <returns></returns> public bool Edit(XmlElement actionXml) { Platform.Log(LogLevel.Info, "Starting Edit of study {0} for Patient {1} (PatientId:{2} A#:{3}) on Partition {4}", Study.StudyInstanceUid, Study.PatientsName, Study.PatientId, Study.AccessionNumber, ServerPartition.Description); LoadExtensions(); EditStudyWorkQueueDataParser parser = new EditStudyWorkQueueDataParser(); EditStudyWorkQueueData data = parser.Parse(actionXml); using (ServerCommandProcessor processor = new ServerCommandProcessor("Web Edit Study")) { // Convert UpdateItem in the request into BaseImageLevelUpdateCommand List <BaseImageLevelUpdateCommand> updateCommands = null; if (data != null) { updateCommands = CollectionUtils.Map <Edit.UpdateItem, BaseImageLevelUpdateCommand>( data.EditRequest.UpdateEntries, delegate(Edit.UpdateItem item) { // Note: For edit, we assume each UpdateItem is equivalent to SetTagCommand return(new SetTagCommand(item.DicomTag.TagValue, item.OriginalValue, item.Value)); } ); } UpdateStudyCommand updateStudyCommand = new UpdateStudyCommand(ServerPartition, StorageLocation, updateCommands, ServerRuleApplyTimeEnum.SopEdited); processor.AddCommand(updateStudyCommand); // Note, this command will only insert the ArchiveQueue command if a delete doesn't exist processor.AddCommand(new InsertArchiveQueueCommand(ServerPartition.Key, StorageLocation.Key)); var context = new WebEditStudyContext { CommandProcessor = processor, EditType = data.EditRequest.EditType, OriginalStudyStorageLocation = StorageLocation, EditCommands = updateCommands, OriginalStudy = Study, OrginalPatient = Patient, UserId = data.EditRequest.UserId, Reason = data.EditRequest.Reason }; OnStudyUpdating(context); if (!processor.Execute()) { Platform.Log(LogLevel.Error, processor.FailureException, "Unexpected failure editing study: {0}", processor.FailureReason); FailureReason = processor.FailureReason; return(false); } // reload the StudyStorageLocation NewStorageLocation = StudyStorageLocation.FindStorageLocations(StorageLocation.StudyStorage)[0]; context.NewStudystorageLocation = NewStorageLocation; OnStudyUpdated(context); if (updateStudyCommand.Statistics != null) { StatisticsLogger.Log(LogLevel.Info, updateStudyCommand.Statistics); } return(true); } }