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");
}
}
private async Task kickOff(int taskID)
{
var profile = _profileStorage.Current;
var taskInfo = $"task: {taskID}";
try
{
//2018-08-16 shb moved from init to enable task restartability after task cancellation.
#if (DEBUG)
if (_taskManager.CanStart("ReadConsole"))
{
var newTaskID = _taskManager.NewTaskID();
Task task = new Task(new Action(async() => await ReadConsole()));
await _taskManager.Start(newTaskID, task, $"ReadConsole", isLongRunning : true);
}
#endif
/*
* 2018-07-05 shb responsive status reports as soon as task completes
*/
if (_taskManager.CanStart("TaskCompletion"))
{
var newTaskID = _taskManager.NewTaskID();
Task task = new Task(new Action(async() => await _taskManager.TaskCompletion(profile)));
await _taskManager.Start(newTaskID, task, $"TaskCompletion", isLongRunning : true);
}
var cloudConnection = _connectionFinder.GetPrimaryLifeImageConnection(profile);
var connectionManager = _connectionManagerFactory.GetManager(cloudConnection) as ILifeImageCloudConnectionManager;
if (cloudConnection.loginNeeded)
{
await connectionManager.login(taskID);
//await profile.GetPrimaryLifeImageConnection().login(taskID);
}
if (!cloudConnection.loginNeeded)
{
kickOffCount++;
profile.lastKickOff = DateTime.Now;
_logger.Log(LogLevel.Debug, $"{taskInfo} kickOffCount: {kickOffCount}");
_logger.Log(LogLevel.Debug, $"{taskInfo} -----------------KickOff----------------");
_logger.Log(LogLevel.Debug, $"{taskInfo} Processing UpgradeDowngrade");
UpgradeDowngrade();
_logger.Log(LogLevel.Debug, $"{taskInfo} Processing Run");
Run();
/*
* 2018-07-06 shb purge async
*/
if ((kickOffCount + 9) % 10 == 0)
{
if (_taskManager.CanStart("Purge"))
{
var newTaskID = _taskManager.NewTaskID();
Task task = new Task(new Action(async() => await _litePurgeService.Purge(newTaskID)));
await _taskManager.Start(newTaskID, task, $"Purge", isLongRunning : false);
}
}
// Process the queues in the connections
foreach (var conn in profile.connections)
{
_logger.Log(LogLevel.Debug, $"{taskInfo} connection: {conn.name} enabled: {conn.enabled}");
if (conn.enabled == false)
{
_logger.Log(LogLevel.Debug, $"{taskInfo} connection: {conn.name} enabled: {conn.enabled} skipping");
continue;
}
/*
* 2018-05-10 shb prevent re-entrancy problems with Kickoff.
*/
if (_taskManager.CanStart($"{conn.name}.Kickoff") && conn.started)
{
var connManager = _connectionManagerFactory.GetManager(conn);
var newTaskID = _taskManager.NewTaskID();
Task task = new Task(new Action(async() => await connManager.Kickoff(newTaskID)), _taskManager.cts.Token);
await _taskManager.Start(newTaskID, task, $"{conn.name}.Kickoff", isLongRunning : false);
}
}
/*
* 2018-06-12 shb status is now long running.
*/
if (_taskManager.CanStart($"UpdateStatus"))
{
var newTaskID = _taskManager.NewTaskID();
Task task = new Task(new Action(async() => await _taskManager.UpdateStatus()));
await _taskManager.Start(newTaskID, task, $"UpdateStatus", isLongRunning : true);
}
}
else
{
_logger.Log(LogLevel.Information, "Primary LifeImage account loginNeeded, skipping kickOff until resolved");
await connectionManager.login(taskID);
//await profile.GetPrimaryLifeImageConnection().login(taskID);
}
}
catch (TaskCanceledException)
{
_logger.Log(LogLevel.Information, $"Task was canceled.");
}
catch (Exception e)
{
_logger.LogFullException(e, taskInfo);
//throw e;
throw;
}
}
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);
}
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");
}
}