/// <summary>
/// Process operations and manage session
/// </summary>
/// <returns></returns>
private async Task RunAsync()
{
// Create a static keep alive operation object for the the session
var keepAlive = (0, new KeepAlive(_keepAlive));
// We cache the current operation as part of sessions state and the priority
// here if operation should be retried next loop
var priority = 0;
var reconnect = false;
var recreate = false;
var retryCount = 0;
// Save identity and certificate to update session if there are changes.
var defaultIdentity = new UserIdentity(_connection.User.ToUserIdentityToken());
try {
while (!_cts.Token.IsCancellationRequested)
{
Exception ex = null;
if (_session == null)
{
// Try create session
recreate = false;
reconnect = false;
try {
try {
if (_curOperation == null && _queue.TryDequeue(out var next))
{
_curOperation = next.Item2;
}
var identity = _curOperation?.Identity ?? defaultIdentity;
_logger.Debug("Creating new session via {endpoint} using {identity}...",
_endpointUrl, identity.DisplayName);
_session = await CreateSessionAsync(identity);
_logger.Debug("Session via {endpoint} created.", _endpointUrl);
}
catch (ServiceResultException sre) {
var ce = sre.ToTypedException();
if (ce is UnauthorizedAccessException uae && _curOperation != null)
{
// the operation identity is not working to establish connection
_curOperation.Fail(uae);
_curOperation = null;
_lastActivity = DateTime.UtcNow;
}
throw;
}
}
catch (Exception e) {
_logger.Information(
"{message} creating session via {endpoint} - retry.",
e.Message, _endpointUrl);
_logger.Debug(e, "Error connecting - retry.");
ex = e;
}
}
if (recreate)
{
// Try recreate session from current one
try {
_logger.Debug("Recreating session via {endpoint}...",
_endpointUrl);
var session = await Task.Run(() => Session.Recreate(_session), _cts.Token);
_logger.Debug("Session recreated via {endpoint}.",
_endpointUrl);
Try.Op(() => _session.Close());
_session = session;
recreate = false;
}
catch (Exception e) {
ex = e;
_logger.Information("{message} while recreating session " +
"via {endpoint} - create new one.",
e.Message, _endpointUrl);
_logger.Debug(e, "Error connecting - create new session.");
_session?.Close();
_session = null;
}
}
if (reconnect)
{
// Try reconnect the session
try {
_logger.Debug("Reconnecting session via {endpoint}...",
_endpointUrl);
#pragma warning disable RECS0002 // Convert anonymous method to method group
await Task.Run(() => _session.Reconnect(), _cts.Token);
#pragma warning restore RECS0002 // Convert anonymous method to method group
_logger.Debug("Session reconnected via {endpoint}.",
_endpointUrl);
reconnect = false;
}
catch (Exception e) {
ex = e;
recreate = true;
reconnect = false;
if (e is ServiceResultException sre)
{
if (sre.StatusCode == StatusCodes.BadTcpEndpointUrlInvalid ||
sre.StatusCode == StatusCodes.BadTcpInternalError ||
sre.StatusCode == StatusCodes.BadCommunicationError ||
sre.StatusCode == StatusCodes.BadNotConnected)
{
if (retryCount < kMaxReconnectAttempts && Pending > 0)
{
_logger.Information("{message} while reconnecting session" +
" via {endpoint} - retry...",
sre.Message, _endpointUrl);
recreate = false;
reconnect = true; // Try again
}
}
}
_logger.Debug(e,
"Error reconnecting via {endpoint} - recreating session...",
_endpointUrl);
}
}
// Failed to connect
if (recreate || reconnect || _session == null)
{
await NotifyConnectivityStateChangeAsync(ToConnectivityState(ex));
if (ex is ServiceResultException sre)
{
ex = sre.ToTypedException();
}
// Compress operations queue
var operations = new List <(int, SessionOperation)>();
while (_queue.TryDequeue(out var op))
{
if (op.Item2 == null)
{
break;
}
operations.Add(op);
}
foreach (var op in operations)
{
if (ex != null && !op.Item2.ShouldRetry(ex))
{
op.Item2.Fail(ex);
}
else if (!op.Item2.IsCompleted())
{
// Re-add the still valid ones...
_queue.Enqueue(op);
}
}
++retryCount;
// Try again to connect with an exponential delay
var delay = Retry.GetExponentialDelay(retryCount,
kMaxReconnectDelayWhenPendingOperations / 2, kMaxRetries);
if (delay > kMaxReconnectDelayWhenPendingOperations)
{
//
// If pending operations, do not delay longer than 5 seconds
// otherwise wait for 2 hours or until new operation is queued.
//
delay = Pending != 0 ? kMaxReconnectDelayWhenPendingOperations :
kMaxReconnectDelayWhenNoPendingOperations;
}
_logger.Information("Try to connect via {endpoint} in {delay} ms...",
_endpointUrl, delay);
// Wait for either the retry delay to pass or until new operation is added
await WaitForNewlyEnqueuedOperationAsync(delay);
continue;
}
// We have a session that should work for us, get next operation and
// complete it.
retryCount = 0;
recreate = false;
reconnect = false;
if (_curOperation == null)
{
if (!_queue.TryDequeue(out var next))
{
// Wait for enqueue or keep alive timeout
var timeout = await WaitForNewlyEnqueuedOperationAsync(
(int)_keepAlive.TotalMilliseconds);
// Check cancellation
if (_cts.Token.IsCancellationRequested)
{
continue;
}
if (timeout || !_queue.TryDequeue(out next))
{
next = keepAlive;
}
}
(priority, _curOperation) = next;
System.Diagnostics.Debug.Assert(_curOperation != null);
}
if (_curOperation.IsCompleted())
{
_curOperation = null; // Already completed because timeout or cancellation, get next
continue;
}
try {
if (_curOperation is KeepAlive)
{
_logger.Verbose("Sending keep alive message...");
}
else
{
// Check if the desired user identity is the same as the current one
if (!Utils.IsEqual((_curOperation.Identity ?? defaultIdentity).GetIdentityToken(),
_session.Identity.GetIdentityToken()))
{
// Try Elevate or de-elevate session
try {
_logger.Verbose("Updating session user identity...");
await Task.Run(() => _session.UpdateSession(_curOperation.Identity,
_session.PreferredLocales));
_logger.Debug("Updated session user identity.");
}
catch (ServiceResultException sre) {
if (StatusCodeEx.IsSecurityError(sre.StatusCode))
{
_logger.Debug(sre, "Failed updating session identity");
await NotifyConnectivityStateChangeAsync(ToConnectivityState(sre));
_curOperation.Fail(sre.ToTypedException());
_curOperation = null;
continue;
}
throw;
}
}
}
await Task.Run(() => _curOperation.Complete(_session), _cts.Token);
_lastActivity = DateTime.UtcNow;
if (!(_curOperation is KeepAlive) || _lastState != EndpointConnectivityState.Unauthorized)
{
await NotifyConnectivityStateChangeAsync(EndpointConnectivityState.Ready);
}
_logger.Verbose("Session operation completed.");
_curOperation = null;
}
catch (Exception e) {
// Process exception - first convert sre into non opc exception
var oex = e;
if (e is ServiceResultException sre)
{
e = sre.ToTypedException();
}
// See which ones we can retry, and which ones we cannot
switch (e)
{
case TimeoutException te:
case ServerBusyException sb:
_logger.Debug(e, "Server timeout error.");
if (_curOperation.ShouldRetry(e))
{
_logger.Information("Timeout error talking {endpoint} " +
"- {error} - try again later...",
_endpointUrl, e.Message);
_queue.Enqueue(priority, _curOperation);
_curOperation = null;
}
else
{
reconnect = _curOperation is KeepAlive;
if (!reconnect)
{
_logger.Error("Timeout error talking to {endpoint} " +
"- {error} - fail user operation.",
_endpointUrl, e.Message);
}
_curOperation.Fail(e);
_curOperation = null;
}
break;
case ConnectionException cn:
case ProtocolException pe:
case CommunicationException ce:
_logger.Debug(e, "Server communication error.");
if (_curOperation.ShouldRetry(e))
{
_logger.Information("Communication error talking to {endpoint} " +
"- {error} - Reconnect and try again...",
_endpointUrl, e.Message);
// Reconnect session
reconnect = true;
}
else
{
reconnect = _curOperation is KeepAlive;
if (!reconnect)
{
_logger.Error("Communication error talking to {endpoint} " +
"- {error} - fail user operation.",
_endpointUrl, e.Message);
}
_curOperation.Fail(e);
_curOperation = null;
}
break;
default:
if (!_cts.IsCancellationRequested)
{
// App error - fail and continue
_logger.Debug(e, "Application error occurred talking to {endpoint} " +
"- fail operation.",
_endpointUrl, e.Message);
reconnect = _curOperation is KeepAlive;
}
else
{
// Session was closed while operation in progress - Set cancelled
_logger.Error("Session via {endpoint} was closed " +
"while operation in progress - cancel operation.",
_endpointUrl, e.Message);
reconnect = false;
}
_curOperation.Fail(e);
_curOperation = null;
break;
}
if (reconnect)
{
await NotifyConnectivityStateChangeAsync(ToConnectivityState(oex, false));
}
}
} // end while
}
catch (OperationCanceledException) {
// Expected on cancellation
}
catch (Exception ex) {
_logger.Error(ex, "Session operation processor exited with exception");
}
finally {
if (_curOperation != null && _curOperation != keepAlive.Item2)
{
_queue.Enqueue(priority, _curOperation);
}
_lastActivity = DateTime.MinValue;
_logger.Verbose("Closing session...");
_session?.Close();
_session = null;
_logger.Debug("Session closed.");
keepAlive.Item2?.Dispose();
}
_logger.Verbose("Processor stopped.");
}
/// <summary>
/// Process operations and manage session
/// </summary>
/// <returns></returns>
private async Task RunAsync()
{
// Create a static keep alive operation object for the the session
var keepAlive = (0, new KeepAlive(_keepAlive));
// We cache the last operation and priority if operation should be
// retried next loop
SessionOperation operation = null;
var priority = 0;
var reconnect = false;
var recreate = false;
var retryCount = 0;
var everSuccessful = _persistent;
// Save identity and certificate to update session if there are changes.
var identity = _endpoint.User.ToStackModel();
try {
while (!_cts.Token.IsCancellationRequested)
{
Exception ex = null;
if (_session == null)
{
// Try create session
recreate = false;
reconnect = false;
try {
_logger.Debug("{session}: Creating new session to {url} via {endpoint}...",
_sessionId, _endpoint.Url, _endpointUrl);
_session = await CreateSessionAsync(identity);
_logger.Debug("{session}: Session to {url} via {endpoint} created.",
_sessionId, _endpoint.Url, _endpointUrl);
}
catch (Exception e) {
_logger.Information(
"{session}: {message} creating session to {url} via {endpoint} - retry.",
_sessionId, e.Message, _endpoint.Url, _endpointUrl);
_logger.Debug(e, "{session}: Error connecting - retry.",
_sessionId);
ex = e;
}
}
if (recreate)
{
// Try recreate session from current one
try {
_logger.Debug("{session}: Recreating session to {url} via {endpoint}...",
_sessionId, _endpoint.Url, _endpointUrl);
var session = await Task.Run(() => Session.Recreate(_session), _cts.Token);
_logger.Debug("{session}: Session recreated to {url} via {endpoint}.",
_sessionId, _endpoint.Url, _endpointUrl);
_session.Close();
_session = session;
recreate = false;
}
catch (Exception e) {
ex = e;
_logger.Information("{session}: {message} while recreating session " +
"to {url} via {endpoint} - create new one.",
_sessionId, e.Message, _endpoint.Url, _endpointUrl);
_logger.Debug(e, "{session}: Error connecting - create new session.",
_sessionId);
_session?.Close();
_session = null;
}
}
if (reconnect)
{
// Try reconnect the session
try {
_logger.Debug("{session}: Reconnecting session to {url} via {endpoint}...",
_sessionId, _endpoint.Url, _endpointUrl);
#pragma warning disable RECS0002 // Convert anonymous method to method group
await Task.Run(() => _session.Reconnect(), _cts.Token);
#pragma warning restore RECS0002 // Convert anonymous method to method group
_logger.Debug("{session}: Session reconnected to {url} via {endpoint}.",
_sessionId, _endpoint.Url, _endpointUrl);
reconnect = false;
}
catch (Exception e) {
ex = e;
recreate = true;
reconnect = false;
if (e is ServiceResultException sre)
{
if (sre.StatusCode == StatusCodes.BadTcpEndpointUrlInvalid ||
sre.StatusCode == StatusCodes.BadTcpInternalError ||
sre.StatusCode == StatusCodes.BadCommunicationError ||
sre.StatusCode == StatusCodes.BadNotConnected)
{
if (retryCount < kMaxReconnectAttempts && Pending > 0)
{
_logger.Information("{session}: {message} while reconnecting session" +
" to {url} via {endpoint} - retry...",
_sessionId, sre.Message, _endpoint.Url, _endpointUrl);
recreate = false;
reconnect = true; // Try again
}
}
}
_logger.Debug(e,
"{session}: Error reconnecting to {url} via {endpoint} - recreating session...",
_sessionId, _endpoint.Url, _endpointUrl);
}
}
// Failed to connect
if (recreate || reconnect || _session == null)
{
await NotifyConnectivityStateChangeAsync(ToConnectivityState(ex));
if (ex is ServiceResultException sre)
{
ex = sre.ToTypedException();
}
// Compress operations queue
var operations = new List <(int, SessionOperation)>();
while (_queue.TryDequeue(out var op))
{
if (op.Item2 == null)
{
break;
}
operations.Add(op);
}
foreach (var op in operations)
{
if (ex != null && !op.Item2.ShouldRetry(ex))
{
op.Item2.Fail(ex);
}
else if (!op.Item2.IsCompleted())
{
// Re-add the still valid ones...
_queue.Enqueue(op);
}
}
++retryCount;
if (!_persistent && retryCount > kMaxEmptyReconnectAttempts && Pending == 0)
{
_logger.Warning(
"{session}: Give up on empty non-persistent session to {url} via {endpoint}...",
_sessionId, _endpoint.Url, _endpointUrl);
break;
}
// Try again to connect with an exponential delay
var delay = Retry.GetExponentialDelay(retryCount,
kMaxReconnectDelayWhenPendingOperations / 2, kMaxRetries);
if (delay > kMaxReconnectDelayWhenPendingOperations)
{
//
// If pending operations, do not delay longer than 5 seconds
// otherwise wait for 2 hours or until new operation is queued.
//
delay = Pending != 0 ? kMaxReconnectDelayWhenPendingOperations :
kMaxReconnectDelayWhenNoPendingOperations;
}
_logger.Information("{session}: Try to connect to {url} via {endpoint} in {delay} ms...",
_sessionId, _endpoint.Url, _endpointUrl, delay);
// Wait for either the retry delay to pass or until new operation is added
await WaitForNewlyEnqueuedOperationAsync(delay);
continue;
}
// We have a session that should work for us, get next operation and
// complete it.
retryCount = 0;
recreate = false;
reconnect = false;
if (operation == null)
{
if (!_queue.TryDequeue(out var next))
{
// Wait for enqueue or keep alive timeout
var timeout = await WaitForNewlyEnqueuedOperationAsync(
(int)_keepAlive.TotalMilliseconds);
// Check cancellation
if (_cts.Token.IsCancellationRequested)
{
continue;
}
if (timeout || !_queue.TryDequeue(out next))
{
next = keepAlive;
}
}
(priority, operation) = next;
}
if (operation.IsCompleted())
{
operation = null; // Already completed because timeout or cancellation, get next
continue;
}
if (operation is KeepAlive)
{
_logger.Verbose("{session}: Sending keep alive message...", _sessionId);
}
try {
// Check if the desired user identity is the same as the current one
if (!Utils.IsEqual((operation.Identity ?? identity).GetIdentityToken(),
_session.Identity.GetIdentityToken()))
{
// Try Elevate or de-elevate session
try {
_logger.Verbose("{session}: Updating session user identity...", _sessionId);
await Task.Run(() => _session.UpdateSession(operation.Identity,
_session.PreferredLocales));
_logger.Debug("{session}: Updated session user identity.", _sessionId);
}
catch (ServiceResultException sre) {
if (StatusCodeEx.IsSecurityError(sre.StatusCode))
{
_logger.Debug(sre, "{session}: Failed updating session identity",
_sessionId);
await NotifyConnectivityStateChangeAsync(ToConnectivityState(sre));
operation.Fail(sre.ToTypedException());
operation = null;
continue;
}
throw;
}
}
await Task.Run(() => operation.Complete(_session), _cts.Token);
_lastActivity = DateTime.UtcNow;
await NotifyConnectivityStateChangeAsync(EndpointConnectivityState.Ready);
everSuccessful = true;
_logger.Verbose("{session}: Session operation completed.", _sessionId);
operation = null;
}
catch (Exception e) {
// Process exception - first convert sre into non opc exception
var oex = e;
if (e is ServiceResultException sre)
{
e = sre.ToTypedException();
}
// See which ones we can retry, and which ones we cannot
switch (e)
{
case TimeoutException te:
case ServerBusyException sb:
_logger.Debug(e, "{session}: Server timeout error.", _sessionId);
if (everSuccessful && operation.ShouldRetry(e))
{
_logger.Information("{session}: Timeout error talking to " +
"{url} via {endpoint} - {error} - try again later...",
_sessionId, _endpoint.Url, _endpointUrl, e.Message);
_queue.Enqueue(priority, operation);
operation = null;
}
else
{
reconnect = operation is KeepAlive;
if (!reconnect)
{
_logger.Error("{session}: Timeout error talking to " +
"{url} via {endpoint}- {error} - fail user operation.",
_sessionId, _endpoint.Url, _endpointUrl, e.Message);
}
operation.Fail(e);
operation = null;
}
break;
case ConnectionException cn:
case ProtocolException pe:
case CommunicationException ce:
_logger.Debug(e, "{session}: Server communication error.", _sessionId);
if (everSuccessful && operation.ShouldRetry(e))
{
_logger.Information("{session}: Communication error talking to " +
"{url} via {endpoint} - {error} - Reconnect and try again...",
_sessionId, _endpoint.Url, _endpointUrl, e.Message);
// Reconnect session
reconnect = true;
}
else
{
reconnect = operation is KeepAlive;
if (!reconnect)
{
_logger.Error("{session}: Communication error talking to " +
"{url} via {endpoint} - {error} - fail user operation.",
_sessionId, _endpoint.Url, _endpointUrl, e.Message);
}
operation.Fail(e);
operation = null;
}
break;
default:
// App error - fail and continue
_logger.Debug(e, "{session}: Application error occurred talking to " +
"{url} via {endpoint} - fail operation.",
_sessionId, _endpoint.Url, _endpointUrl, e.Message);
reconnect = operation is KeepAlive;
operation.Fail(e);
operation = null;
break;
}
if (reconnect || !everSuccessful)
{
await NotifyConnectivityStateChangeAsync(ToConnectivityState(oex, false));
}
if (!everSuccessful)
{
break; // Give up here - might have just been used to test endpoint
}
}
} // end while
}
catch (OperationCanceledException) {
// Expected on cancellation
}
catch (Exception ex) {
_logger.Error(ex, "{session}: Session operation processor exited with exception",
_sessionId);
}
finally {
if (operation != null)
{
_queue.Enqueue(priority, operation);
}
_lastActivity = DateTime.MinValue;
_logger.Verbose("{session}: Closing session...", _sessionId);
_session?.Close();
_session = null;
_logger.Debug("{session}: Session closed.", _sessionId);
}
_logger.Verbose("{session}: Processor stopped.", _sessionId);
}
