Online Forums

Technical support is provided through Support Forums below. Anybody can view them; you need to Register/Login to our site (see links in upper right corner) in order to Post questions. You do not have to be a licensed user of our product.

Please read Rules for forum posts before reporting your issue or asking a question. OPC Labs team is actively monitoring the forums, and replies as soon as possible. Various technical information can also be found in our Knowledge Base. For your convenience, we have also assembled a Frequently Asked Questions page.

Do not use the Contact page for technical issues.

Subscription stopped firing events

1
2
3

sjscheider
Topic Author
Offline
Platinum Member

More

15 Jul 2019 15:06 #7526 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

Sorry, I initially gave you the version of the assemblies we are using in our production code. In our test app, we are using the following versions:
OpcLabs.BaseLib.dll = 5.54.1281.1
OpcLabs.EasyOpcClassic.dll = 5.54.0.0
OpcLabs.EasyOpcUA.dll = 5.54.1281.1

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

15 Jul 2019 15:02 #7525 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

support wrote: Hello.
Answering:

"Is QuickOPC supposed to handle subscription "timing-out" because of a lack of activity? "
No. Even in absence of true data changes, OPC UA protocol exchanges kind of keep-alive messages, so in fact there is no "inactivity".

"Should an event fire? "
If there was a true inactivity, meaning that the keep-alive messages were not being exchanged, yes, an event should fire, with an error. If the data is not changing but keep-alives are OK, there should be no event fired by QuickOPC to your code. But of course when there finally is new data, they should be sent to you.

Best regards

Understood, but why are we not receiving any data change events. If I use UaExpert client, I see occasional data changes, maybe every hour or so.

Won't the keep-alive eventually stop after some period of time without data changes?

Is there any way more me to monitor the keep-alive messages in OPC Labs?

If needed, my boss is OK with us sharing our simulator with you. We can also provide out test app code as well. If this is something you want to explore, please email me directly. (I'm assuming you have access to my email address. If not, please let me know how to reach you.)

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

15 Jul 2019 14:55 #7524 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

Here are the version number of the assemblies:
OpcLabs.BaseLib.dll = 5.54.1156.1
OpcLabs.EasyOpcClassic.dll = 5.54.0.0
OpcLabs.EasyOpcUA.dll = 5.54.1156.1

I noticed there is a newer version on NuGet, I'll try that one today.

Please Log in or Create an account to join the conversation.

support
Away
Moderator

More

15 Jul 2019 13:51 #7523 by support

Replied by support on topic Subscription stopped firing events

Hello.
Answering:

"Is QuickOPC supposed to handle subscription "timing-out" because of a lack of activity? "
No. Even in absence of true data changes, OPC UA protocol exchanges kind of keep-alive messages, so in fact there is no "inactivity".

"Should an event fire? "
If there was a true inactivity, meaning that the keep-alive messages were not being exchanged, yes, an event should fire, with an error. If the data is not changing but keep-alives are OK, there should be no event fired by QuickOPC to your code. But of course when there finally is new data, they should be sent to you.

Best regards

Please Log in or Create an account to join the conversation.

support
Away
Moderator

More

15 Jul 2019 09:37 #7522 by support

Replied by support on topic Subscription stopped firing events

Hello,

thank you for the additional information.
Which QuickOPC build are you running? (the last two numbers in 5.54.x.y, as taken form the actual assemblies you are building against and testing with).

Best regards

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

12 Jul 2019 12:48 #7521 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

Some additional information. When I run in the VS debugger, the issue does not appear to occur. It only happens when I run as a standalone app.

Here are the logs messages that occur between successful data change events in the debugger.

2019-07-12 00:56:32.852 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 is connecting to endpoint URL "opc.tcp://127.0.0.1:4840".
2019-07-12 00:56:32.853 -04:00 [WRN] <10> OpcUaSubscriptionTest2.Program DataChangeCallbackAnalogInputs 127.0.0.1:4840 nodeName: n/a - StatusInfo: Unknown - ErrorCode: -1 - ErrorMessageBrief: OPC-UA client session is not available when connecting the client subscription.  - DiagnosticsSummary:  
2019-07-12 00:56:32.865 -04:00 [DBG] <10> OpcUaSubscriptionTest2.Program DataChangeCallbackAnalogInputs 127.0.0.1:4840 StatusInfo: Unknown, ErrorCode: -1, ErrorMessageBrief: OPC-UA client session is not available when connecting the client subscription., ErrorMessage: OPC-UA client session is not available when connecting the client subscription., DiagnosticsCount: 0, DiagnosticsSummary: , Succeeded: False, Arguments: "opc.tcp://127.0.0.1:4840", "NodeId="nsu=urn:VersumMaterials:UA:AP11CGGIIIController;ns=3;i=2"", Value, Arguments.AttributeId: Value, Arguments.AutoConditionRefresh: True, Arguments.EndpointDescriptor: opc.tcp://127.0.0.1:4840, Arguments.NodeDescriptor: NodeId="nsu=urn:VersumMaterials:UA:AP11CGGIIIController;ns=3;i=2", Arguments.State:  
2019-07-12 00:56:32.858 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 for discovery URL "opc.tcp://127.0.0.1:4840" will use an endpoint selection policy that has warnings. The policy warnings are:
- An endpoint with obsolete security policy may be selected by this policy.
2019-07-12 00:56:32.865 -04:00 [WRN] <10> OpcUaSubscriptionTest2.Program DataChangeCallbackAnalogInputs 127.0.0.1:4840 nodeName: n/a - StatusInfo: Unknown - ErrorCode: -1 - ErrorMessageBrief: OPC-UA client session is not available when connecting the client subscription.  - DiagnosticsSummary:  
2019-07-12 00:56:32.869 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: OPC-UA endpoint selection on discovery URL "opc.tcp://127.0.0.1:4840" candidate report (1 entries) follows.
[0:Winner(1)].
2019-07-12 00:56:32.872 -04:00 [INF] <10> OpcUaSubscriptionTest2.Program ServerConditionChanged n/a EndpointDescriptor: opc.tcp://127.0.0.1:4840
		ConnectionState:    Connecting
		StatusInfo:         Error
		ErrorMessageBrief:  OPC-UA service result - An error specific to OPC-UA service occurred.
		ErrorMessage:       OPC-UA service result - An error specific to OPC-UA service occurred.
---- SERVICE RESULT ----
Status Code: {BadSecureChannelClosed} = 0x80860000 (2156265472)
Description: BadSecureChannelClosed
Additional Info: <ExceptionTrace>
-----
Status Code: {BadTcpSecureChannelUnknown} = 0x807F0000 (2155806720)
Description: Could not verify security on response.
-----
Status Code: {BadTcpSecureChannelUnknown} = 0x807F0000 (2155806720)
Description: Token #1 has expired. Lifetime=04:46:17.784
Additional Info: <ExceptionTrace>
---- REMARKS ----
The server may have rejected the connection because it does not trust the client (e.g. certificate problem); check the diagnostics on the server side, if possible.
 
		DiagnosticsCount:   0
		DiagnosticsSummary: 
		Succeeded:          False
		Connected:          False
 
2019-07-12 00:56:32.879 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The preference for endpoint selection was not to use security, but the OPC-UA server endpoint URL "opc.tcp://127.0.0.1:4840", selected using discovery on endpoint URL "opc.tcp://127.0.0.1:4840", has message security mode 'SignAndEncrypt'. This happens when no unsecured endpoints are available and eligible for selection.
2019-07-12 00:56:32.957 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: An OPC UA endpoint has been selected and normalized. Endpoint URL: "opc.tcp://127.0.0.1:4840", security mode: 'SignAndEncrypt', security policy URI: "http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256", transport profile URI: "http://opcfoundation.org/UA-Profile/Transport/uatcp-uasc-uabinary"
2019-07-12 00:56:32.970 -04:00 [INF] <10> OpcUaSubscriptionTest2.Program ServerConditionChanged n/a EndpointDescriptor: opc.tcp://127.0.0.1:4840
		ConnectionState:    Connected
		StatusInfo:         Error
		ErrorMessageBrief:  OPC-UA service result - An error specific to OPC-UA service occurred.
		ErrorMessage:       OPC-UA service result - An error specific to OPC-UA service occurred.
---- SERVICE RESULT ----
Status Code: {BadSecureChannelClosed} = 0x80860000 (2156265472)
Description: BadSecureChannelClosed
Additional Info: <ExceptionTrace>
-----
Status Code: {BadTcpSecureChannelUnknown} = 0x807F0000 (2155806720)
Description: Could not verify security on response.
-----
Status Code: {BadTcpSecureChannelUnknown} = 0x807F0000 (2155806720)
Description: Token #1 has expired. Lifetime=04:46:17.784
Additional Info: <ExceptionTrace>
---- REMARKS ----
The server may have rejected the connection because it does not trust the client (e.g. certificate problem); check the diagnostics on the server side, if possible.
 
		DiagnosticsCount:   0
		DiagnosticsSummary: 
		Succeeded:          False
		Connected:          True
2019-07-12 00:56:32.983 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 has preselected an OPC-UA endpoint for discovery URL "opc.tcp://127.0.0.1:4840" with following parameters:
Endpoint URL "opc.tcp://127.0.0.1:4840", message security mode 'SignAndEncrypt', security policy URI "http://opcfoundation.org/UA/SecurityPolicy#Basic256Sha256", transport profile URI "http://opcfoundation.org/UA-Profile/Transport/uatcp-uasc-uabinary, use binary encoding: yes. 
2019-07-12 00:56:33.007 -04:00 [INF] <10> OpcUaSubscriptionTest2.Program ServerConditionChanged n/a EndpointDescriptor: opc.tcp://127.0.0.1:4840
		ConnectionState:    Connected
2019-07-12 00:56:33.018 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 user token selection on endpoint URL "opc.tcp://127.0.0.1:4840" candidate report (2 entries) follows.
[0:Winner(""), 1:ValidNotEligible(NotApplicable("http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-username-token-profile-1.0"))].
2019-07-12 00:56:33.031 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 on endpoint URL "opc.tcp://127.0.0.1:4840" has been associated with user identity token type 'Anonymous', display name "Anonymous".
2019-07-12 00:56:33.035 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA server on endpoint URL "opc.tcp://127.0.0.1:4840" returned an empty list of software certificates.
2019-07-12 00:56:33.038 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA client session with connect sequence number 3 has successfully connected to endpoint URL "opc.tcp://127.0.0.1:4840". The server-assigned session Id is "g=a381de9e-988c-ff10-9a43-cdcf57c75059".
2019-07-12 00:56:33.044 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription on client session with connect sequence number 3 to endpoint URL "opc.tcp://127.0.0.1:4840" has been successfully created and checked, and given subscription ID 9. Revised publishing interval is 7500, keep-alive count is 11520 and lifetime count is 34560. 
2019-07-12 00:56:33.046 -04:00 [WRN] <19> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription on client session with connect sequence number 3 to endpoint URL "opc.tcp://127.0.0.1:4840" has been successfully created and checked, and given subscription ID 10. Revised publishing interval is 1000, keep-alive count is 5 and lifetime count is 15.

Here is the messages the occurs when run as a standalone app.

2019-07-12 08:32:33.286 -04:00 [WRN] <39> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription ID 12 publishing has stopped on the client session with connect sequence number 1 to endpoint URL "opc.tcp://127.0.0.1:4840" for approximate current duration of 5753 milliseconds. The current keep-alive count is 5, the current publishing interval is 1000 milliseconds, and the probationary period will be 5000 milliseconds. Further such errors on this session will not be logged.
		EventId:        3021
		EntryType:      Warning
		Category:       0
		Source:         OPCLabs-UAEngine
		Timestamp:      7/12/2019 12:32:33 PM
		TimestampLocal: 7/12/2019 8:32:33 AM
		RawData:        [null]
 
2019-07-12 08:32:33.536 -04:00 [WRN] <25> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription ID 12 publishing has recovered on the client session with connect sequence number 1 to endpoint URL "opc.tcp://127.0.0.1:4840". It has been stopped for 250 milliseconds. Further such warnings on this session will not be logged.
		EventId:        3022
		EntryType:      Information
		Category:       0
		Source:         OPCLabs-UAEngine
		Timestamp:      7/12/2019 12:32:33 PM
		TimestampLocal: 7/12/2019 8:32:33 AM
		RawData:        [null]

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

12 Jul 2019 04:06 #7516 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

I just wanted to explain out test in a little more detail. Typically when we are testing, we are running our server in simulation mode which basically toggles a few data points ever 1 or 2 seconds to cause the data change events to fire. Whenever we run against the server in this mode we never have a problem since there is constant activity. When we deployed the code to customer, they have a few devices/server that are idle and not really generating much activity. The issue occurs when the customer starts using an idle device, none of the data changes code through.

We basically mimicked this by running our server with no data changing occurring automatically. We then manually change the data on the server which causes the data change events to occur in the client. But if we stop for about 15 minutes, the events stop occurring on the client. The data is changing on the server.

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

12 Jul 2019 03:49 #7515 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

OK, we've been able to reproduce in our test environment. First, I created a simple client app to subscribe to 1 node on 1 server. Next, we manually changed a few data points on the server in the complex object to demonstrate that the data change event firsts and it did. Then we waited about 15 minutes and manually changed a few more data points and we never received any events on the client. Both the server and client are indicating that connection is still valid. We made these code changes is the thought to cause the issue quicker.

_easyUaClient.IsolatedParameters.SubscriptionParameters.KeepAliveCount = 2;
_easyUaClient.IsolatedParameters.SubscriptionParameters.LifetimeCount = 6;

No events fired on the client. We have handlers for all events and none of these handlers were initiated.

Is QuickOPC supposed to handle subscription "timing-out" because of a lack of activity? Should an event fire? I guess I'm just trying to figure out how this is supposed to work.

Here is basically the code that initiates the subscription.

            EasyUAClient.SharedParameters.EngineParameters.ApplicationParameters.ApplicationName = "XXXXXXXXXXXX";
            EasyUAClient.SharedParameters.EngineParameters.CertificateAcceptancePolicy.AcceptAnyCertificate = true;
 
            EasyUAClient.SharedParameters.EngineParameters.ApplicationParameters.ApplicationCertificateStore = @"C:\xxx\certstore\machinedefaults";
            EasyUAClient.SharedParameters.EngineParameters.CertificateAcceptancePolicy.RejectedCertificateStore = @"C:\xxx\certstore\rejectedcerts";
            EasyUAClient.SharedParameters.EngineParameters.CertificateAcceptancePolicy.TrustedIssuersCertificateStore = @"C:\xxx\certstore\ua-cert-auth";
            EasyUAClient.SharedParameters.EngineParameters.CertificateAcceptancePolicy.TrustedPeersCertificateStore = @"C:\xxx\certstore\ua-apps";
 
            EasyUAClient.LogEntry += EasyUaClientOnLogEntry;
 
            _easyUaClient = new EasyUAClient {Isolated = true};
 
            _easyUaClient.EventNotification += ClientEventNotification;
            _easyUaClient.ServerConditionChanged += ServerConditionChanged;
            _easyUaClient.Disposed += DisposedEventHandler;
            _easyUaClient.DataChangeNotification += DataChangeCallbackAnalogInputs;
 
            _easyUaClient.IsolatedParameters.SubscriptionParameters.KeepAliveCount = 2;
            _easyUaClient.IsolatedParameters.SubscriptionParameters.LifetimeCount = 6;
 
            SubscribeToNodes(controllerId, endpoint, "AnalogInputs", "nsu=urn:XXXXXXXXXXUA:AP11CGGIIIController;ns=3;i=2", 1000);

Here are the results of a the ServerConditionChanged event and a couple LogEntry events.

2019-07-11 22:51:39.321 -04:00 [INF] <16> OpcUaSubscriptionTest2.Program ServerConditionChanged n/a EndpointDescriptor: opc.tcp://127.0.0.1:4840
		ConnectionState:    Connected
		StatusInfo:         Normal
		ErrorMessageBrief:  
		ErrorMessage:       
		DiagnosticsCount:   0
		DiagnosticsSummary: 
		Succeeded:          True
		Connected:          True
 
2019-07-11 22:51:39.340 -04:00 [WRN] <15> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription on client session with connect sequence number 1 to endpoint URL "opc.tcp://127.0.0.1:4840" has been successfully created and checked, and given subscription ID 1. Revised publishing interval is 7500, keep-alive count is 10 and lifetime count is 1000.
		EventId:        3002
		EntryType:      Information
		Category:       0
		Source:         OPCLabs-UAEngine
		Timestamp:      7/12/2019 2:51:39 AM
		TimestampLocal: 7/11/2019 10:51:39 PM
		RawData:        [null]
 
2019-07-11 22:51:39.370 -04:00 [WRN] <15> OpcUaSubscriptionTest2.Program EasyUaClientOnLogEntry n/a Message: The OPC-UA subscription on client session with connect sequence number 1 to endpoint URL "opc.tcp://127.0.0.1:4840" has been successfully created and checked, and given subscription ID 2. Revised publishing interval is 1000, keep-alive count is 5 and lifetime count is 15.
		EventId:        3002
		EntryType:      Information
		Category:       0
		Source:         OPCLabs-UAEngine
		Timestamp:      7/12/2019 2:51:39 AM
		TimestampLocal: 7/11/2019 10:51:39 PM
		RawData:        [null]

I'm going to analyze the dumpfile next but I'm not sure what I'll find. Any other suggestions? This is a pretty straight forward test.

Please Log in or Create an account to join the conversation.

support
Away
Moderator

More

09 Jul 2019 09:26 #7507 by support

Replied by support on topic Subscription stopped firing events

Hello.

Having LogEntry notifications would be helpful, to see if there is anything related to the devices in question.
My expectation is, however, that there won't be any related events. In such case, it might be a deadlock inside the component. We have had it in the past, with similar symptoms. The way to diagnose it was to break into debugger, collect call stacks of all threads, and then analyze whether there is a deadlock and which threads and call sequences are involved. Of course, the more is running, the more data there is to analyze and it becomes difficult, but it is worth trying.

With .NET Framework, it was possible to obtain a memory dump (which included the call stacks) and analyze it off-line (here). In principle, the same should be possible with .NET Core, at least under Windows, but I have not done that yet. See e.g. michaelscodingspot.com/how-to-create-use-and-debug-net-application-crash-dumps-in-2019/ .

Best regards

Please Log in or Create an account to join the conversation.

sjscheider
Topic Author
Offline
Platinum Member

More

04 Jul 2019 18:15 #7497 by sjscheider

Replied by sjscheider on topic Subscription stopped firing events

We unfortunately have not been able to reproduce the issue in our local test environment yet so my details on this are still evolving. The issue is only occurring at our customer's location which only adds to the complication and stress.

Our customer has indicated that they have seen the issue with only 3 controllers/devices connected. I've actually witness the issue when 100+ devices were connected. In all cases, restarting the client all solved the issue.

We've added more diagnostics to our code to determine if we can get any insights into the issue. Any recommendations you have would be greatly appreciated.

Please Log in or Create an account to join the conversation.

1
2
3

Moderators: support

Time to create page: 0.096 seconds

Powered by Kunena Forum

Joomla SEF URLs by Artio