private async Task <string> ProcessItem(BourneListens bourne, List <TcpClient> clients, Func <TcpClient, int, Task> func, int taskID) { //You can echo "Hello world!" | nc ::1 2575 to send messages to accept a new connection request TcpClient client = await bourne.AcceptTcpClientAsync(); string remote = client.Client.RemoteEndPoint.ToString(); var local = bourne.LocalEndpoint.ToString(); _logger.Log(LogLevel.Debug, $"{local} connected to: {remote}"); if (clients.Count < Connection.maxInboundConnections && _taskManager.CanStart($"{Connection.name}.read")) { clients.Add(client); _logger.Log(LogLevel.Debug, $"{local} added to clients: {remote}"); var endpoint = client.Client.RemoteEndPoint; var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await func(client, newTaskID)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.read", $"{Connection.name}.read: {remote}", isLongRunning : false); } else { _logger.Log(LogLevel.Warning, $"{local} Max Connections: {Connection.maxInboundConnections} reached."); _logger.Log(LogLevel.Debug, $"client connection closed {taskID} due to max connections reached"); client.Close(); } return(local); }
private async Task ProcessItem(int taskID, RoutedItem routedItem, LITEConnection connection, IHttpManager httpManager) { var taskInfo = $"task: {taskID} connection: {Connection.name}"; if (routedItem.lastAttempt == null || routedItem.lastAttempt >= DateTime.Now.AddMinutes(-connection.retryDelayMinutes)) //not attempted lately { await Task.CompletedTask; return; } routedItem.attempts++; if (routedItem.attempts > 1) { _logger.Log(LogLevel.Debug, $"{taskInfo} {routedItem.sourceFileName} second attempt."); } routedItem.lastAttempt = DateTime.Now; if (routedItem.attempts > connection.maxAttempts) { _logger.Log(LogLevel.Warning, $"Resource {routedItem.resource} exceeded max attempts. Deleting item."); if (await _deleteEGSResourceService.DeleteEGSResource(taskID, routedItem, connection, httpManager)) { _routedItemManager.Init(routedItem); _routedItemManager.Dequeue(connection, connection.fromEGS, nameof(connection.fromEGS), error: false); } else { routedItem.Error = "Exceeded maxAttempts"; _routedItemManager.Init(routedItem); _routedItemManager.Dequeue(connection, connection.fromEGS, nameof(connection.fromEGS), error: true); } } switch (Connection.protocol) { case Protocol.Http: // while (!LITETask.CanStart($"{name}.DownloadViaHttp")) // { // await Task.Delay(LITE.profile.taskDelay).ConfigureAwait(false); // } var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _downloadViaHttpService.DownloadViaHttp(newTaskID, routedItem, connection, httpManager)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.DownloadViaHttp", routedItem.resource, isLongRunning : false).ConfigureAwait(false); //await DownloadViaHttp(newTaskID, ri).ConfigureAwait(false); break; // case Protocol.UDT: // await DownloadViaUDTShell(remoteHostname, remotePort, $"{routedItem.box + "/" + routedItem.resource}", LITE.profile.tempPath + Path.DirectorySeparatorChar + "toScanner", taskID); // break; } }
public async Task Upload(int taskID, LifeImageCloudConnection Connection, ILifeImageCloudConnectionManager manager, IConnectionRoutedCacheManager cache, IHttpManager httpManager) { var taskInfo = $"task: {taskID} connection: {Connection.name}"; _logger.Log(LogLevel.Debug, $"{taskInfo} Entering Upload"); try { bool success = await manager.ToCloudSignal.WaitAsync(_profileStorage.Current.KickOffInterval, _taskManager.cts.Token) .ConfigureAwait(false); // ToCloudSignal.Dispose(); // ToCloudSignal = new SemaphoreSlim(0, 1); await _sendToCloudService.SendToCloud(taskID, Connection, cache, httpManager); //if (_profileStorage.Current.rules.DoesRouteDestinationExistForSource(Connection.name)) if (_rulesManager.DoesRouteDestinationExistForSource(Connection.name)) { if (_taskManager.CanStart($"{Connection.name}.GetRequests")) { var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _cloudAgentTaskLoader.GetRequests(taskID, Connection, cache, httpManager)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.GetRequests", isLongRunning : false); } } } catch (TaskCanceledException) { _logger.Log(LogLevel.Information, $"{taskInfo} Task was canceled."); } catch (OperationCanceledException) { _logger.Log(LogLevel.Warning, $"{taskInfo} Wait Operation Canceled. Exiting Upload"); } catch (Exception e) { _logger.LogFullException(e, taskInfo); _logger.Log(LogLevel.Critical, $"{taskInfo} Exiting Upload"); } finally { _taskManager.Stop($"{Connection.name}.Upload"); } }
public async Task Process() { var taskInfo = $""; var profile = _profileStorage.Current; _logger.Log(LogLevel.Information, "Life Image Transfer Exchange Loop"); try { try { lock (ProfileLocker) { _profileManager.LoadProfile(profile, profile.startupParams.localProfilePath); //Profile.LoadProfile(profile, profile.startupParams.localProfilePath); if (profile.duplicatesDetectionUpload) { string message = "Duplicates detection and elimination process is active for upload process."; _logger.Log(LogLevel.Information, $"{message}"); } else { string message = "Duplicates detection and elimination process is not active for upload process."; _logger.Log(LogLevel.Information, $"{message}"); } if (profile.duplicatesDetectionDownload) { string message = "Duplicates detection and elimination process is active for download process."; _logger.Log(LogLevel.Information, $"{message}"); } else { string message = "Duplicates detection and elimination process is not active for download process."; _logger.Log(LogLevel.Information, $"{message}"); } //var primaryConnection = profile.GetPrimaryLifeImageConnection(); var primaryConnection = _connectionFinder.GetPrimaryLifeImageConnection(profile); if (primaryConnection == null) { throw new Exception($"Primary Connection Missing out of {profile.connections.Capacity} total connections."); } if (platform.Equals("win") && string.IsNullOrEmpty(profile.dcmtkLibPath)) { Console.WriteLine(profile.name); profile.dcmtkLibPath = "tools" + Path.DirectorySeparatorChar + Constants.Dirs.dcmtk + Path.DirectorySeparatorChar + "dcmtk-3.6.3-win64-dynamic"; //profile.SaveProfile(); _profileWriter.SaveProfile(profile).Wait(); } if (!primaryConnection.loginNeeded) { _cloudProfileLoaderService.LoadProfile(profile, primaryConnection).Wait(); //profile.LoadProfile(primaryConnection).Wait(); } //profile.SaveProfile(); _profileWriter.SaveProfile(profile).Wait(); bool isEnabled = false; AppContext.TryGetSwitch("System.Net.Http.useSocketsHttpHandler", out isEnabled); if (isEnabled != profile.useSocketsHttpHandler) { _logger.Log(LogLevel.Debug, $"{taskInfo} Calling AppContext.SetSwitch(\"System.Net.Http.useSocketsHttpHandler\", {profile.useSocketsHttpHandler})"); AppContext.SetSwitch("System.Net.Http.useSocketsHttpHandler", profile.useSocketsHttpHandler); } } } catch (Exception e) { if (e.Message.Contains("Replacement Strategy Needs Full LITE.init()")) { _logger.Log(LogLevel.Critical, $"{taskInfo} Configuration changed received."); } else { _logger.LogFullException(e, $"{taskInfo} Profile Operations Problem: {e.Message}"); } throw e; } //adjust loglevel if necessary // _logger.LogLevel = profile.logger.logLevel; Logger.logger.ConsoleTraceLevel = profile.logger.ConsoleTraceLevel; Logger.logger.FileTraceLevel = profile.logger.FileTraceLevel; Logger.logger.SplunkTraceLevel = profile.logger.SplunkTraceLevel; Logger.logger.TracePattern = profile.logger.TracePattern; //compile the scripts as needed foreach (var myscript in profile.rules.scripts) { if (myscript.script == null) { _logger.Log(LogLevel.Debug, $"compiling {myscript.name}"); _scriptService.Compile(myscript); } } //let's queue up some work _logger.Log(LogLevel.Information, "Life Image Transfer Exchange kickoff start"); var newTaskID = _taskManager.NewTaskID(); await kickOff(newTaskID); _logger.Log(LogLevel.Information, "Life Image Transfer Exchange kickoff end"); if (profile.backlogDetection) { foreach (var conn in profile.connections) { if (conn.toRules.Count > 0) { profile.backlog = true; } } if (profile.backlog) { _logger.Log(LogLevel.Debug, $"{taskInfo} Detected Backlog, skipping kickoffInterval"); await Task.Delay(profile.backlogInterval, _taskManager.cts.Token); profile.backlog = false; } else { await Task.Delay(profile.KickOffInterval, _taskManager.cts.Token); } } else { await Task.Delay(profile.KickOffInterval, _taskManager.cts.Token); } RecoveryCount = 0; } catch (Exception e) { if (LITETask._shutdown) { throw new Exception("Application is terminated"); } ; if (e.Message.Contains("Replacement Strategy Needs Full LITE.init()")) { } else { _logger.Log(LogLevel.Critical, $"{taskInfo} Life Image Transfer Exchange Loop Exception: breaking out of run loop due to unrecoverable exception. {e.Message}"); if (e.InnerException != null) { _logger.Log(LogLevel.Critical, $"Inner Exception: {e.InnerException}"); } } } }
private async Task ProcessScanPath(int taskID, FileConnection Connection, IConnectionRoutedCacheManager connectionManager, string fileEntry) { var taskInfo = $"task: {taskID} connection: {Connection.name}"; _logger.Log(LogLevel.Debug, $"{taskInfo} fileEntry: {fileEntry}"); //Expand home dir syntax ex: ~/blah string filestr = _fileExpanderService.Expand(fileEntry); _logger.Log(LogLevel.Debug, $"{taskInfo} expanded: {filestr}"); // get the file attributes for file or directory // FileAttributes attr = File.GetAttributes(fileEntry); string directory = filestr; _logger.Log(LogLevel.Debug, $"{taskInfo} create directory: {directory}"); var directoryFullPath = Path.GetDirectoryName(directory); Directory.CreateDirectory(directoryFullPath); //This may cause problems if we are specifying files instead of directories. Directory.CreateDirectory(directory); //This may cause problems if we are specifying files instead of directories. string searchPattern; if (filestr.IndexOf("*") != -1) { _logger.Log(LogLevel.Debug, $"{taskInfo} wildcard search pattern detected."); directory = Path.GetDirectoryName(filestr); searchPattern = Path.GetFileName(filestr); } else { _logger.Log(LogLevel.Debug, $"{taskInfo} using search pattern *."); searchPattern = "*"; } FileAttributes attr = File.GetAttributes(directory); if (!attr.HasFlag(FileAttributes.Directory)) { _logger.Log(LogLevel.Debug, $"{taskInfo} Sending individually specified {filestr}."); await _sendFileService.SendFile(filestr, taskID, Connection, connectionManager); return; } _logger.Log(LogLevel.Debug, $"{taskInfo} This is a directory."); var fileEntries = _util.DirSearch(directory, searchPattern); if (_profileStorage.Current.duplicatesDetectionUpload) { _logger.Log(LogLevel.Information, $"{taskInfo} toCloud: {(fileEntries == null ? 0 : fileEntries.Count)} files to be send to cloud (before duplicates elimination)."); } else { _logger.Log(LogLevel.Information, $"{taskInfo} toCloud: {(fileEntries == null ? 0 : fileEntries.Count)} files to be send to cloud."); } foreach (string file in fileEntries) { _logger.Log(LogLevel.Debug, $"{taskInfo} Found {file}."); try { attr = File.GetAttributes(file); if (!attr.HasFlag(FileAttributes.Hidden)) { var newTaskID = _taskManager.NewTaskID(); await _sendFileService.SendFile(file, newTaskID, Connection, connectionManager); } else { _logger.Log(LogLevel.Debug, $"{taskInfo} Deleting hidden file {file}."); File.Delete(file); //delete hidden files like .DS_Store } } catch (FileNotFoundException e) { _logger.Log(LogLevel.Debug, $"Retrieve Exception: {e.Message} {e.StackTrace}"); //eat it if not found, it's already gone } } //cleanup empty directories. _logger.Log(LogLevel.Debug, $"{taskInfo} Cleaning Empty Directories {directory}."); _util.CleanUpDirectory(directory); }
private async Task StartImpl(HL7Connection Connection, List <BourneListens> listeners, ObservableCollection <BourneListens> deadListeners, List <TcpClient> clients, Func <TcpClient, int, Task> Read) { RemoveDeadListeners(listeners, deadListeners); //frequent DNS lookup required for Cloud and HA environments where a lower TTL results in faster failover. //For a listener this means a container might have been moved to another server with different IP. var hostEntry = Dns.GetHostEntry(Connection.localHostname); foreach (var ip in hostEntry.AddressList) { _logger.Log(LogLevel.Information, $"{Connection.name} hostEntry: {Connection.localHostname} ip: {ip}"); BourneListens bourne = null; if (ip.AddressFamily == AddressFamily.InterNetworkV6 && Connection.UseIPV6) { if (!listeners.Exists(x => x.localaddr.Equals(ip) && x.port.Equals(Connection.localPort))) { bourne = new BourneListens(ip, Connection.localPort); listeners.Add(bourne); //you can verify Start worked on mac by doing lsof -n -i:2575 | grep LISTEN, where 2575 is HL7 or whatever port you want. bourne.Start(); _logger.Log(LogLevel.Information, $"{Connection.name} is listening on {bourne.LocalEndpoint}"); _logger.Log(LogLevel.Information, $"{Connection.name} Verify with Mac/Linux:lsof -n -i:{Connection.localPort} | grep LISTEN and with echo \"Hello world\" | nc {Connection.localHostname} {Connection.localPort}"); _logger.Log(LogLevel.Information, $"{Connection.name} Verify with Windows:netstat -abno (requires elevated privileges)"); } } if ((ip.AddressFamily == AddressFamily.InterNetwork && Connection.UseIPV4 && !RuntimeInformation.IsOSPlatform(OSPlatform.Windows)) || (ip.AddressFamily == AddressFamily.InterNetwork && Connection.UseIPV4 && !Connection.UseIPV6 && RuntimeInformation.IsOSPlatform(OSPlatform.Windows))) { if (!listeners.Exists(x => x.localaddr.Equals(ip) && x.port.Equals(Connection.localPort))) { bourne = new BourneListens(ip, Connection.localPort); listeners.Add(bourne); //you can verify Start worked on mac by doing lsof -n -i:2575 | grep LISTEN, where 2575 is HL7 or whatever port you want. bourne.Start(); _logger.Log(LogLevel.Information, $"{Connection.name} is listening on {bourne.LocalEndpoint}"); _logger.Log(LogLevel.Information, $"{Connection.name} Verify with Mac/Linux:lsof -n -i:{Connection.localPort} | grep LISTEN and with echo \"Hello world\" | nc {Connection.localHostname} {Connection.localPort}"); _logger.Log(LogLevel.Information, $"{Connection.name} Verify with Windows:netstat -abno (requires elevated privileges)"); } } } foreach (var listener in listeners) { if (listener != null && listener.LocalEndpoint != null) { if (_taskManager.CanStart($"{Connection.name}.accept: {listener.LocalEndpoint}")) { var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _hl7AcceptService.Accept(Connection, listener, clients, Read, newTaskID)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.accept: {listener.LocalEndpoint}", $"{Connection.name}.accept: {listener.LocalEndpoint}", isLongRunning : true); await Task.Delay(1000); } } else { _logger.Log(LogLevel.Information, $"listener is disposed but still in list. Ignoring"); } } }
public async Task SendToEGS(int taskID, LITEConnection connection, ISendToAllHubsService sendToAllHubs) { Connection = connection; //2018-02-02 shb RoutedItem does not necessarily have an open stream at this point any more var taskInfo = $"task: {taskID} connection: {Connection.name}"; _logger.Log(LogLevel.Information, $"{taskInfo} toEGS: {(Connection.toEGS == null ? 0 : Connection.toEGS.Count)} items to send."); Dictionary <string, List <RoutedItem> > shareSet = new Dictionary <string, List <RoutedItem> >(); //I need a set for each sharing dest set List <List <RoutedItem> > sizeSet = new List <List <RoutedItem> >(); //I need a set for each minEGSBatchSize try { Task.WaitAll(_taskManager.FindByType($"{Connection.name}.PresentAsResource")); Task.WaitAll(_taskManager.FindByType($"{Connection.name}.Store")); int retryDelayed = 0; if (Connection.toEGS.Count > 0) { var toEGSTemp = Connection.toEGS.ToArray(); //remove the toCloud item if it has exceeded maxAttempts foreach (var routedItem in toEGSTemp) { if (_taskManager.cts.IsCancellationRequested) { return; } if (routedItem.lastAttempt != null && routedItem.lastAttempt < DateTime.Now.AddMinutes(-Connection.retryDelayMinutes)) //not attempted lately { routedItem.attempts++; if (routedItem.attempts > 1) { _logger.Log(LogLevel.Debug, $"{taskInfo} {routedItem.sourceFileName} second attempt."); } routedItem.lastAttempt = DateTime.Now; if (routedItem.attempts > Connection.maxAttempts) { _logger.Log(LogLevel.Error, $"{taskInfo} {routedItem.sourceFileName} has exceeded maxAttempts of {Connection.maxAttempts}. Will move to errors and not try again."); routedItem.Error = "Exceeded maxAttempts"; _routedItemManager.Init(routedItem); _routedItemManager.Dequeue(Connection, Connection.toEGS, nameof(Connection.toEGS), error: true); } else { _logger.Log(LogLevel.Information, $"{taskInfo} {routedItem.sourceFileName} attempts: {routedItem.attempts}"); } //inspect the sharing headers and batch by set string shareString = ""; if (Connection.shareDestinations != null) { foreach (var connectionSet in routedItem.toConnections.FindAll(e => e.connectionName.Equals(Connection.name))) { if (connectionSet.shareDestinations != null) { foreach (var shareDestination in connectionSet.shareDestinations) { shareString += shareDestination.boxUuid; } } } } if (shareSet.ContainsKey(shareString)) { _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {routedItem.sourceFileName} to shareString: {shareString}"); shareSet.GetValueOrDefault(shareString).Add(routedItem); } else { var list = new List <RoutedItem> { routedItem }; _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {routedItem.sourceFileName} to shareString: {shareString}"); shareSet.Add(shareString, list); } } else { retryDelayed++; } } //Now that each key in the Dictionary is to a single set of sharing destinations, let's break it up further by minEGSBatchSize //What we want is a big enough upload to solve the small file problem, but small enough so the upload makes forward progress. //If this is not the first attempt, then disable batching and send individually. foreach (var share in shareSet.Values) { if (_taskManager.cts.IsCancellationRequested) { return; } var batch = new List <RoutedItem>(); long bytes = 0; foreach (var element in share) { if (File.Exists(element.sourceFileName)) { try { element.length = new FileInfo(element.sourceFileName).Length; } catch (FileNotFoundException e) { _logger.Log(LogLevel.Error, $"{taskInfo} {e.Message} {e.StackTrace}"); continue; } catch (IOException e) { _logger.Log(LogLevel.Error, $"{taskInfo} {e.Message} {e.StackTrace}"); //condition may be transient like file in use so skip for the moment continue; } catch (Exception e) { _logger.LogFullException(e, taskInfo); //condition may be transient like file so skip for the moment continue; } } else { element.Error = $"File {element.sourceFileName} does not exist"; _routedItemManager.Init(element); _routedItemManager.Dequeue(Connection, Connection.toEGS, nameof(Connection.toEGS), true); } //If this is not the first attempt, then disable batching and send individually. if (element.length < Connection.minEGSBatchSize && bytes < Connection.minEGSBatchSize && element.attempts == 1) { bytes += element.length; _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {element.sourceFileName} to batch..."); batch.Add(element); } else { _logger.Log(LogLevel.Debug, $"{taskInfo} Batch is full with count: {batch.Count} size: {bytes} attempts: {element.attempts} {(element.attempts > 1 ? "items are sent individually after 1st attempt!" : "")}"); sizeSet.Add(batch); batch = new List <RoutedItem>(); bytes = element.length; batch.Add(element); } } if (!sizeSet.Contains(batch) && batch.Count > 0) { _logger.Log(LogLevel.Debug, $"{taskInfo} Add final batch to set with count: {batch.Count} size: {bytes}"); sizeSet.Add(batch); } } int tempcount = 0; foreach (var batch in sizeSet) { tempcount += batch.Count; } _logger.Log(LogLevel.Information, $"{taskInfo} {sizeSet.Count} batches to send, selected: {tempcount}/{toEGSTemp.Length} retry delayed: {retryDelayed}"); foreach (var batch in sizeSet) { if (_taskManager.cts.IsCancellationRequested) { return; } //if (loginNeeded) break; if (batch.Count > 0) { switch (Connection.PushPull) { case PushPullEnum.pull: switch (Connection.protocol) { case Protocol.Http: case Protocol.UDT: var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _presentAsResourceService.PresentAsResource(batch, newTaskID, connection, sendToAllHubs))); await _taskManager.Start(newTaskID, task, $"{Connection.name}.PresentAsResource", $"{Connection.name}.PresentAsResource batch {batch.Count}", isLongRunning : false); break; } break; case PushPullEnum.push: switch (Connection.protocol) { case Protocol.Http: var newTaskID2 = _taskManager.NewTaskID(); Task task2 = new Task(new Action(async() => await _liteStoreService.store(batch, newTaskID2, connection))); await _taskManager.Start(newTaskID2, task2, $"{Connection.name}.Store", $"{Connection.name}.Store batch {batch.Count}", isLongRunning : false); break; case Protocol.UDT: break; } break; case PushPullEnum.both: //since each method dequeues it's own work we would need a separate queue before we can do both, like toEGSPull toEGSPush. break; } } } } } catch (TaskCanceledException) { _logger.Log(LogLevel.Information, $"Task was canceled."); } catch (Exception e) { _logger.LogFullException(e, taskInfo); } }
public async Task SendToCloud(int taskID, LifeImageCloudConnection Connection, IConnectionRoutedCacheManager cacheManager, IHttpManager httpManager) { //2018-02-02 shb RoutedItem does not necessarily have an open stream at this point any more var taskInfo = $"task: {taskID} connection: {Connection.name}"; _logger.Log(LogLevel.Information, $"{taskInfo} toCloud: {(Connection.toCloud == null ? 0 : Connection.toCloud.Count)} suggested items to send."); Dictionary <string, List <RoutedItem> > shareSet = new Dictionary <string, List <RoutedItem> >(); //I need a set for each sharing dest set List <List <RoutedItem> > sizeSet = new List <List <RoutedItem> >(); //I need a set for each minStowBatchSize try { Task.WaitAll(_taskManager.FindByType($"{Connection.name}.putHL7")); Task.WaitAll(_taskManager.FindByType($"{Connection.name}.PostResponse")); Task.WaitAll(_taskManager.FindByType($"{Connection.name}.Stow")); int retryDelayed = 0; List <RoutedItem> toCloudTemp = new List <RoutedItem>(); if (Connection.toCloud.Count <= 0) { await Task.CompletedTask; return; } lock (Connection.toCloud) { foreach (var routedItem in Connection.toCloud) { if (_profileStorage.Current.duplicatesDetectionUpload && routedItem.type == RoutedItem.Type.DICOM && routedItem.sourceFileName != null) { _duplicatesDetectionService.DuplicatesPurge(); lock (routedItem) { if (!_duplicatesDetectionService.DuplicatesReference(routedItem.fromConnection, routedItem.sourceFileName)) { continue; } } } if (routedItem.lastAttempt == null || (routedItem.lastAttempt != null && routedItem.lastAttempt < DateTime.Now.AddMinutes(-Connection.retryDelayMinutes))) { //not attempted lately routedItem.attempts++; routedItem.lastAttempt = DateTime.Now; if (routedItem.attempts > 1) { _logger.Log(LogLevel.Debug, $"{taskInfo} type: {routedItem.type} id: {routedItem.id} file: {routedItem.sourceFileName} meta: {routedItem.RoutedItemMetaFile} second attempt."); } toCloudTemp.Add(routedItem); } else { retryDelayed++; } } } foreach (var routedItem in toCloudTemp) { //remove the toCloud item if it has exceeded maxAttempts if (routedItem.attempts > Connection.maxAttempts) { // AMG LITE-1090 - put a break on then execution (add continue statement) and add routedItem status to the message. _logger.Log(LogLevel.Error, $"{taskInfo} type: {routedItem.type} id: {routedItem.id} status: {routedItem.status} file: {routedItem.sourceFileName} meta: {routedItem.RoutedItemMetaFile} has exceeded maxAttempts of {Connection.maxAttempts}. Will move to errors and not try again (removed from send queue)."); _routedItemManager.Init(routedItem); _routedItemManager.Dequeue(Connection, Connection.toCloud, nameof(Connection.toCloud), error: true); continue; } else { _logger.Log(LogLevel.Information, $"{taskInfo} type: {routedItem.type} id: {routedItem.id} file: {routedItem.sourceFileName} meta: {routedItem.RoutedItemMetaFile} attempt: {routedItem.attempts}"); } switch (routedItem.type) { case RoutedItem.Type.RPC: { _logger.Log(LogLevel.Debug, $"{taskInfo} PostResponse ID: {routedItem.id}"); var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _postResponseCloudService.PostResponse(Connection, routedItem, cacheManager, httpManager, newTaskID)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.PostResponse", $"{Connection.name}.PostResponse {routedItem.id}", isLongRunning : false); } break; case RoutedItem.Type.HL7: { _logger.Log(LogLevel.Debug, $"{taskInfo} putHL7 file: {routedItem.sourceFileName}"); var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _sendFromCloudToHl7Service.putHL7(routedItem, newTaskID, Connection, httpManager)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.putHL7", $"{Connection.name}.putHL7 {routedItem.sourceFileName}", isLongRunning : false); } break; case RoutedItem.Type.COMPLETION: { _logger.Log(LogLevel.Debug, $"{taskInfo} Completion ID: {routedItem.id} type: {routedItem.type} "); var newTaskID = _taskManager.NewTaskID(); Task task = new Task( new Action(async() => await _postCompletionCloudService.PostCompletion(Connection, routedItem, cacheManager, httpManager, newTaskID)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.PostCompletion", $"{Connection.name}.PostCompletion {routedItem.id}", isLongRunning : false); } break; case RoutedItem.Type.DICOM: case RoutedItem.Type.FILE: //check if dicom, if not dicomize since cloud only does dicom via stow. if (File.Exists(routedItem.sourceFileName) && !_dicomUtil.IsDICOM(routedItem)) { _dicomUtil.Dicomize(routedItem); } //inspect the sharing headers and batch by set string shareString = ""; if (Connection.shareDestinations != null) { foreach (var connectionSet in routedItem.toConnections.FindAll(e => e.connectionName.Equals(Connection.name))) { if (connectionSet.shareDestinations != null) { foreach (var shareDestination in connectionSet.shareDestinations) { shareString += shareDestination.boxUuid; } } } } if (shareSet.ContainsKey(shareString)) { _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {routedItem.sourceFileName} to shareString: {shareString}"); shareSet.GetValueOrDefault(shareString).Add(routedItem); } else { var list = new List <RoutedItem> { routedItem }; _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {routedItem.sourceFileName} to shareString: {shareString}"); shareSet.Add(shareString, list); } break; default: _logger.Log(LogLevel.Critical, $"{taskInfo} meta: {routedItem.RoutedItemMetaFile} Unsupported type: {routedItem.type}"); break; } } //Now that each key in the Dictionary is to a single set of sharing destinations, let's break it up further by minStowBatchSize //What we want is a big enough upload to solve the small file problem, but small enough so the upload makes forward progress. //If this is not the first attempt, then disable batching and send individually. foreach (var share in shareSet.Values) { var batch = new List <RoutedItem>(); long bytes = 0; foreach (var element in share) { try { element.length = new FileInfo(element.sourceFileName).Length; } catch (FileNotFoundException e) { _logger.Log(LogLevel.Critical, $"{taskInfo} id: {element.id} meta:{element.RoutedItemMetaFile} source:{element.sourceFileName} type:{element.type} {e.Message} {e.StackTrace}"); _routedItemManager.Init(element); _routedItemManager.Dequeue(Connection, Connection.toCloud, nameof(Connection.toCloud), true); continue; } catch (IOException e) { _logger.Log(LogLevel.Critical, $"{taskInfo} id: {element.id} meta:{element.RoutedItemMetaFile} source:{element.sourceFileName} type:{element.type} {e.Message} {e.StackTrace}"); //condition may be transient like file in use so skip for the moment continue; } catch (Exception e) { _logger.Log(LogLevel.Critical, $"{taskInfo} id: {element.id} meta:{element.RoutedItemMetaFile} source:{element.sourceFileName} type:{element.type} {e.Message} {e.StackTrace}"); if (e.InnerException != null) { _logger.Log(LogLevel.Critical, $"Inner Exception: {e.InnerException}"); } //condition may be transient like file so skip for the moment continue; } //If this is not the first attempt, then disable batching and send individually. if (element.length < Connection.minStowBatchSize && bytes < Connection.minStowBatchSize && element.attempts == 1) { bytes += element.length; _logger.Log(LogLevel.Debug, $"{taskInfo} Adding {element.sourceFileName} to batch..."); batch.Add(element); } else { _logger.Log(LogLevel.Debug, $"{taskInfo} Batch is full with count: {batch.Count} size: {bytes} attempts: {element.attempts} {(element.attempts > 1 ? "items are sent individually after 1st attempt!" : "")}"); sizeSet.Add(batch); batch = new List <RoutedItem>(); bytes = element.length; batch.Add(element); } } if (!sizeSet.Contains(batch) && batch.Count > 0) { _logger.Log(LogLevel.Debug, $"{taskInfo} Add final batch to set with count: {batch.Count} size: {bytes}"); sizeSet.Add(batch); } } int tempcount = 0; foreach (var batch in sizeSet) { tempcount += batch.Count; } _logger.Log(LogLevel.Information, $"{taskInfo} {sizeSet.Count} batches to send, selected: {tempcount}/{toCloudTemp.Count} retry delayed: {retryDelayed}"); foreach (var batch in sizeSet) { if (httpManager.loginNeeded) { break; } if (batch.Count > 0) { var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _stowAsMultiPartCloudService.stowAsMultiPart(batch, newTaskID, Connection, httpManager)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.Stow", $"{Connection.name}.Stow batch {batch.Count}", isLongRunning : false); } } } catch (TaskCanceledException) { _logger.Log(LogLevel.Information, $"{taskInfo} Task was canceled."); } catch (Exception e) { _logger.LogFullException(e, taskInfo); } }
private async Task <bool> ProcessImageStudy(LifeImageCloudConnection Connection, ImagingStudy imagingStudy, IHttpManager httpManager, string taskInfo) { string duplicatesDirName = Connection.name; if (_profileStorage.Current.duplicatesDetectionDownload) { _duplicatesDetectionService.DuplicatesPurge(); lock (imagingStudy) { if (!_duplicatesDetectionService.DuplicatesReference1(duplicatesDirName, imagingStudy.uid)) { //studies.ImagingStudy.Remove(imagingStudy); return(false); } } } _logger.Log(LogLevel.Information, $"{taskInfo} checking study: {imagingStudy.uid} downloadStarted:{imagingStudy.downloadStarted:yyyy-MM-dd HH:mm:ss.ffff} downloadCompleted:{imagingStudy.downloadCompleted:yyyy-MM-dd HH:mm:ss.ffff} attempts: {imagingStudy.attempts} seriesOverMaxAttempts:{imagingStudy.series?.FindAll(e => e.attempts > Connection.maxAttempts).Count}"); if (await _taskManager.CountByReference(imagingStudy.uid) != 0) //not in task { _logger.Log(LogLevel.Information, $"{taskInfo} study: {imagingStudy.uid} in current tasks. Skipping."); return(false); } _logger.Log(LogLevel.Debug, $"{taskInfo} study: {imagingStudy.uid} not in current tasks."); if (imagingStudy.downloadCompleted != DateTime.MinValue) //not completed { _logger.Log(LogLevel.Information, $"{taskInfo} study: {imagingStudy.uid} completed. Skipping."); return(false); } _logger.Log(LogLevel.Debug, $"{taskInfo} study: {imagingStudy.uid} not completed."); if (imagingStudy.downloadStarted >= DateTime.Now.AddMinutes(-Connection.retryDelayMinutes)) //not attempted lately { _logger.Log(LogLevel.Information, $"{taskInfo} study: {imagingStudy.uid} attempted lately. Skipping."); return(false); } _logger.Log(LogLevel.Debug, $"{taskInfo} study: {imagingStudy.uid} not attempted lately."); if ((imagingStudy.series?.FindAll(e => e.attempts > Connection.maxAttempts).Count) != 0) //not exceeded max attempts { _logger.Log(LogLevel.Information, $"{taskInfo} study: {imagingStudy.uid} has exceeded max attempts. Skipping."); return(false); } _logger.Log(LogLevel.Debug, $"{taskInfo} study: {imagingStudy.uid} has not exceeded max attempts."); _logger.Log(LogLevel.Information, $"{taskInfo} study: {imagingStudy.uid} attempts: {imagingStudy.attempts} selected for download."); imagingStudy.downloadStarted = DateTime.Now; imagingStudy.attempts++; var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _studyManager.DownloadStudy(newTaskID, imagingStudy, Connection, httpManager)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.downloadStudy", $"{imagingStudy.uid}", isLongRunning : false); return(true); }
/// Responds to a cstore request, which kicks off a StreamToRules task public DicomCStoreResponse OnCStoreRequest(DicomCStoreRequest request) { var taskID = _taskManager.NewTaskID(); var taskInfo = $"task: {taskID} messageID: {request.MessageID} connection: {((DICOMConnection)(base.UserState)).name}"; try { var fromConnection = _connectionFinder.GetDicomConnectionToLocalAETitle(_profileStorage.Current, Association.CalledAE); if (fromConnection == null) { //We have an inbound Association.CalledAE that we aren't configured for logger.Log(LogLevel.Warning, $"{taskInfo} There is no connection defined where the LocalAETitle matches the Association.CalledAE: {Association.CalledAE}"); return(new DicomCStoreResponse(request, DicomStatus.ProcessingFailure)); } logger.Log(LogLevel.Information, $"{taskInfo} CStoreRequest from {fromConnection.name}"); var conn = ((DICOMConnection)(base.UserState)); // var dir = profile.tempPath + Path.DirectorySeparatorChar + ((DICOMConnection)(base.UserState)).name + Path.DirectorySeparatorChar + "toRules"; // Directory.CreateDirectory(dir); // var filename = dir + Path.DirectorySeparatorChar + System.Guid.NewGuid(); // LifeImageLite.Logger.logger.Log(TraceEventType.Verbose, $"{taskInfo} Moving from {request.File.File.Name} to {filename}"); // request.File.File.Move(dstFileName: filename); RoutedItem routedItem = new RoutedItem( fromConnection: fromConnection.name, sourceFileName: request.File.File.Name, taskID: taskID) { type = RoutedItem.Type.DICOM }; request.Dataset.TryGetValue <string>(DicomTag.PatientID, 0, out routedItem.PatientID); request.Dataset.TryGetValue <string>(DicomTag.AccessionNumber, 0, out routedItem.AccessionNumber); request.Dataset.TryGetValue <string>(DicomTag.StudyInstanceUID, 0, out routedItem.Study); request.Dataset.TryGetValue <string>(DicomTag.StudyID, 0, out routedItem.StudyID); foreach (var item in request.Command) { logger.Log(LogLevel.Debug, $"Command tag: {item.Tag} value: {item.ValueRepresentation}"); } routedItem.id = $"PID:{routedItem.PatientID}, AN:{routedItem.AccessionNumber}"; // , UID:{routedItem.Study}"; //profile.rules.SendToRules(routedItem).Wait(); routedItem.priority = _util.GetPriority((ushort)request.Priority); _routedItemManager.Init(routedItem); _routedItemManager.Enqueue(conn, conn.toRules, nameof(conn.toRules), copy: true); DicomStatus status = DicomStatus.Success; DicomCStoreResponse response = new DicomCStoreResponse(request, status) { //Dataset = request.Dataset }; response.Command.AddOrUpdate(DicomTag.AffectedSOPInstanceUID, request.Dataset.GetValue <string>(DicomTag.SOPInstanceUID, 0)); response.Command.AddOrUpdate(DicomTag.AffectedSOPClassUID, request.Dataset.GetValue <string>(DicomTag.SOPClassUID, 0)); return(response); } catch (Exception e) { logger.Log(LogLevel.Critical, $"{taskInfo} {e.Message} {e.StackTrace}"); if (e.InnerException != null) { logger.Log(LogLevel.Critical, $"Inner Exception: {e.InnerException}"); } request.Dataset.AddOrUpdate(DicomTag.AffectedSOPInstanceUID, request.Dataset.GetValue <string>(DicomTag.SOPInstanceUID, 0)); return(new DicomCStoreResponse(request, new DicomStatus(DicomStatus.ProcessingFailure, $"CStore Response Exception: {e.Message} {e.StackTrace}"))); //out of resources not much flexibility here } finally { } }
public async Task DownloadStudy(int taskID, ImagingStudy imagingStudy, LifeImageCloudConnection connection, IHttpManager httpManager) { var Connection = connection; var stopWatch = new Stopwatch(); var taskInfo = $"task: {taskID} connection: {Connection.name}"; try { stopWatch.Start(); _logger.Log(LogLevel.Debug, $"{taskInfo} downloading study: {imagingStudy.uid} downloadStarted: {imagingStudy.downloadStarted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} downloadCompleted: {imagingStudy.downloadCompleted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} attempts: {imagingStudy.attempts}"); foreach (var series in imagingStudy?.series) { _logger.Log(LogLevel.Debug, $"{taskInfo} checking series: {series.uid} downloadStarted: {series.downloadStarted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} downloadCompleted: {series.downloadCompleted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} attempts: {series.attempts}"); if (series.downloadCompleted == DateTime.MinValue) //not completed { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} not completed."); if (series.downloadStarted < DateTime.Now.AddMinutes(-Connection.retryDelayMinutes)) //not attempted lately { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} not attempted lately."); if (imagingStudy.series?.FindAll(e => e.attempts > Connection.maxAttempts).Count == 0) //not exceeded max attempts { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} not exceeded max attempts."); var url = $"{imagingStudy.url}/series/{series.uid.Substring(8)}"; //if the tasklist already contains this series don't add it again //equal is determined by the reference field only //so in this case it is the imagingStudy.url if (await _taskManager.CountByReference(url) == 0) { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} not in task list."); _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} selected for download downloadStarted: {series.downloadStarted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} downloadCompleted: {series.downloadCompleted.ToString("yyyy-MM-dd HH:mm:ss.ffff")} attempts: {series.attempts}"); series.downloadStarted = DateTime.Now; series.attempts++; var newTaskID = _taskManager.NewTaskID(); Task task = new Task(new Action(async() => await _studiesDownloadManager.wadoAsFileStream(connection: connection, newTaskID, httpManager: httpManager, study: imagingStudy, series: series)), _taskManager.cts.Token); await _taskManager.Start(newTaskID, task, $"{Connection.name}.Wado", url, isLongRunning : false); } else { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} in task list. Skipping."); } } else { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} exceeded max attempts. Skipping."); } } else { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} attempted lately. Skipping."); } } else { _logger.Log(LogLevel.Debug, $"{taskInfo} series: {series.uid} completed. Skipping."); } } stopWatch.Stop(); _logger.Log(LogLevel.Information, $"{taskInfo} method level elapsed: {stopWatch.Elapsed} study: {imagingStudy.uid}"); } catch (TaskCanceledException) { _logger.Log(LogLevel.Information, $"{taskInfo} Task was canceled."); } catch (Exception e) { _logger.LogFullException(e, taskInfo); } finally { _taskManager.Stop($"{Connection.name}.downloadStudy"); } }