Skip to content

Reconnecting does not work, client runs into infinite reconnect loop #2368

Closed

Description

[24-11-11 07:41:39.4087] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaSubscription[0]
      Disposed of subscription 4f5b10f21e3acb9aba123ea071afae8c4f9b7e54_0:0 with all 66 items in it...
[24-11-11 07:41:39.4092] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaSession[0]
      opc.tcp://xx.xxx.xxx.200:4840_29DEE054_opc.tcp://xx.xxx.xxx.200:4840_Group: Session disposed.
[24-11-11 07:41:39.4104] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Could not reconnect the Session. Opc.Ua.ServiceResultException: Could not recreate session. opc.tcp://xx.xxx.xxx.200:4840_29DEE054_opc.tcp://xx.xxx.xxx.200:4840_Group
       ---> Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.SessionClient.CreateSessionAsync(RequestHeader requestHeader, ApplicationDescription clientDescription, String serverUri, String endpointUrl, String sessionName, Byte[] clientNonce, Byte[] clientCertificate, Double requestedSessionTimeout, UInt32 maxResponseMessageSize, CancellationToken ct)
         at Opc.Ua.Client.Session.OpenAsync(String sessionName, UInt32 sessionTimeout, IUserIdentity identity, IList`1 preferredLocales, Boolean checkDomain, CancellationToken ct)
         at Opc.Ua.Client.Session.RecreateAsync(Session sessionTemplate, CancellationToken ct)
         --- End of inner exception stack trace ---
         at Opc.Ua.Client.Session.RecreateAsync(Session sessionTemplate, CancellationToken ct)
         at Opc.Ua.Client.Session.RecreateAsync(Session sessionTemplate, ITransportChannel transportChannel, CancellationToken ct)
         at Opc.Ua.Client.DefaultSessionFactory.RecreateAsync(ISession sessionTemplate, ITransportChannel transportChannel, CancellationToken ct)
         at Opc.Ua.Client.SessionReconnectHandler.DoReconnectAsync()
[24-11-11 07:41:39.6454] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:39.6454] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:40.2952] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Error|refs:1]: Session opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group with opc.tcp://xx.xxx.xxx.50:4840 changed from Connecting to Error
[24-11-11 07:41:40.2952] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      #1 - opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Error|refs:1]: Failed to connect to opc.tcp://xx.xxx.xxx.50:4840/: Error establishing a connection: BadNotConnected...
[24-11-11 07:41:40.2952] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Error|refs:1]: Retrying connecting session in 00:00:00.5000000...
[24-11-11 07:41:40.7458] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:40.7460] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:40.7954] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Connecting|refs:1]: Session opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group with opc.tcp://xx.xxx.xxx.50:4840 changed from Error to Connecting
[24-11-11 07:41:40.7954] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Connecting|refs:1]: Connecting to opc.tcp://xx.xxx.xxx.50:4840...
[24-11-11 07:41:41.6160] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadNotConnected
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.QueueConnectOperation(WriteOperation operation, Int32 timeout, IServiceRequest request)
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:41.6174] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.ck[0]
      Publish #59644, Reconnecting=False, Error: BadSecureChannelClosed
[24-11-11 07:41:41.8456] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:41.8456] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:42.9456] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:42.9457] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnectionClosed
         at Opc.Ua.Bindings.UaSCUaBinaryClientChannel.BeginSendRequest(IServiceRequest request, Int32 timeout, AsyncCallback callback, Object state)
         at Opc.Ua.Client.Session.BeginPublish(Int32 timeout)
[24-11-11 07:41:43.2952] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xxx:4840_Group [state:Error|refs:1]: Session opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xxx:4840_Group with opc.tcp://xx.xxx.xxx.50:4840 changed from Connecting to Error
[24-11-11 07:41:43.2952] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      #1 - opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xxx0:4840_Group [state:Error|refs:1]: Failed to connect to opc.tcp://xx.xxx.xxx.50:4840/: Error establishing a connection: BadNotConnected...
[24-11-11 07:41:43.2953] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Error|refs:1]: Retrying connecting session in 00:00:00.5000000...
[24-11-11 07:41:43.7957] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Connecting|refs:1]: Session opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group with opc.tcp://xx.xxx.xxx.50:4840 changed from Error to Connecting
[24-11-11 07:41:43.7957] info: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaClient[0]
      opc.tcp://xx.xxx.xxx.50:4840_8B31B0AD_opc.tcp://xx.xxx.xxx.50:4840_Group [state:Connecting|refs:1]: Connecting to opc.tcp://xx.xxx.xxx.50:4840...
[24-11-11 07:41:44.0450] fail: Azure.IIoT.OpcUa.Publisher.Stack.Services.OpcUaStack[0]
      Unexpected error sending publish request.
      Opc.Ua.ServiceResultException: BadConnect
....

Activity

  1. marcschier commented on Dec 17, 2024

    @marcschier
    CollaboratorAuthor

    At minimum the client should use a exponential backoff retry policy and the publish requests should not be sent during that time. This is larger work we are tracking for post 2.9.12

  2. marcschier commented on Feb 25, 2025

    @marcschier
    CollaboratorAuthor
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions