Ejemplo n.º 1
0
        /// <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.");
        }
Ejemplo n.º 2
0
        /// <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);
        }