opc-ua-client: Error publishing subscription. The session cannot be used because ActivateSession has not been called.

We are using the opc-ua-client library to connect to multiple OPC UA servers, and we are having issues only with one server. We are using client library version 2.2.1 What we do in short:

Open a channel
Read a few tags

_channel = new UaTcpSessionChannel (
	appDescription,
	certificateStore,
	ShowSignInDialog,
	remoteEndpoint: new EndpointDescription {
		EndpointUrl = DiscoveryUrl,
		SecurityPolicyUri = securityPolicyUri,
		SecurityMode = messageSecurityMode },
	loggerFactory: EnableInternalLogs ? loggerFactory : new LoggerFactory(),
	options: new UaTcpSessionChannelOptions()
	{
		TimeoutHint = SessionChannelTimeout
	}
);
await _channel.OpenAsync().ConfigureAwait(false);
...
ReadValueId rVal = new ReadValueId
{
	NodeId = BuildNodeId(namespaceIdx, id, idType),
	AttributeId = AttributeIds.Value
};
ReadResponse response = await _channel.ReadAsync(new ReadRequest()
{
	NodesToRead = new ReadValueId[] { rVal }
}).ConfigureAwait(false);

Log(LogLevel.Info, $"{rVal.NodeId.NamespaceIndex}:{rVal.NodeId.Identifier}={response.Results[0].Value}");

What happens:

The result of tag readings is empty. We receive no values.
After a minute or so the following error occurres and the communication is broken:

“Error publishing subscription. The session cannot be used because ActivateSession has not been called.”

We tried different scenarios, but all the same.
Using UAExpert everything works fine.

Here are all relevant logs, those marked [INTERNAL] are from the client library:

[2020-02-24 14:03:37.3566] [DEBUG] Creating a session with the server… [2020-02-24 14:03:37.3566] [DEBUG] SecurityPolicyUri: ‘http://opcfoundation.org/UA/SecurityPolicy#None’. [2020-02-24 14:03:37.3566] [DEBUG] SecurityMode: ‘None’. [2020-02-24 14:03:37.3625] [DEBUG] UserIdentity: ‘’. [2020-02-24 14:03:37.3625] [INFO] [INTERNAL] Discovering endpoints of ‘opc.tcp://192.168.1.120:4840’. [2020-02-24 14:03:37.3625] [DEBUG] [INTERNAL] Channel opening. [2020-02-24 14:03:37.4267] [DEBUG] [INTERNAL] Sending OpenSecureChannelRequest, Handle: 1 [2020-02-24 14:03:37.4622] [DEBUG] [INTERNAL] Received OpenSecureChannelResponse, Handle: 1 Result: 0x00000000 [2020-02-24 14:03:37.4737] [DEBUG] [INTERNAL] Channel opened. [2020-02-24 14:03:37.4737] [DEBUG] [INTERNAL] Sending GetEndpointsRequest, Handle: 2 [2020-02-24 14:03:37.4909] [DEBUG] [INTERNAL] Installed new security token 1. [2020-02-24 14:03:37.4960] [DEBUG] [INTERNAL] Received GetEndpointsResponse, Handle: 2 Result: 0x00000000 [2020-02-24 14:03:37.5047] [DEBUG] [INTERNAL] Channel closing. [2020-02-24 14:03:37.5082] [DEBUG] [INTERNAL] Sending CloseSecureChannelRequest, Handle: 3 [2020-02-24 14:03:37.5269] [ERROR] [INTERNAL] Error closing secure channel. Timeout occurred while processing the request. [2020-02-24 14:03:37.5269] [DEBUG] [INTERNAL] Channel closed. [2020-02-24 14:03:37.5325] [DEBUG] [INTERNAL] Success discovering endpoints of ‘opc.tcp://192.168.1.120:4840’. [2020-02-24 14:03:37.5374] [DEBUG] Client is building Anonymous identity… [2020-02-24 14:03:37.5374] [DEBUG] Done building identity. [2020-02-24 14:03:37.5374] [DEBUG] [INTERNAL] Channel opening. [2020-02-24 14:03:37.5387] [DEBUG] Opening channel with endpoint ‘opc.tcp://192.168.1.120:4840’. [2020-02-24 14:03:37.5610] [INFO] [INTERNAL] Opening session channel with endpoint ‘opc.tcp://192.168.1.120:4840’. [2020-02-24 14:03:37.5610] [INFO] [INTERNAL] SecurityPolicy: ‘http://opcfoundation.org/UA/SecurityPolicy#None’. [2020-02-24 14:03:37.5610] [INFO] [INTERNAL] SecurityMode: ‘None’. [2020-02-24 14:03:37.5610] [INFO] [INTERNAL] UserIdentity: ‘Workstation.ServiceModel.Ua.AnonymousIdentity’. [2020-02-24 14:03:37.5756] [DEBUG] [INTERNAL] Sending OpenSecureChannelRequest, Handle: 1 [2020-02-24 14:03:37.5790] [DEBUG] [INTERNAL] Received OpenSecureChannelResponse, Handle: 1 Result: 0x00000000 [2020-02-24 14:03:37.5835] [DEBUG] [INTERNAL] Sending CreateSessionRequest, Handle: 2 [2020-02-24 14:03:37.6029] [DEBUG] [INTERNAL] Installed new security token 1. [2020-02-24 14:03:37.6029] [DEBUG] [INTERNAL] Received CreateSessionResponse, Handle: 2 Result: 0x00000000 [2020-02-24 14:03:37.6120] [DEBUG] [INTERNAL] Sending ActivateSessionRequest, Handle: 3 [2020-02-24 14:03:37.6321] [DEBUG] [INTERNAL] Received ActivateSessionResponse, Handle: 3 Result: 0x00000000 [2020-02-24 14:03:37.6368] [DEBUG] [INTERNAL] Sending ReadRequest, Handle: 4 [2020-02-24 14:03:37.6636] [DEBUG] [INTERNAL] Received ReadResponse, Handle: 4 Result: 0x00000000 [2020-02-24 14:03:37.6701] [DEBUG] [INTERNAL] Sending CreateSubscriptionRequest, Handle: 5 [2020-02-24 14:03:37.6806] [DEBUG] [INTERNAL] Received CreateSubscriptionResponse, Handle: 5 Result: 0x00000000 [2020-02-24 14:03:37.6831] [DEBUG] [INTERNAL] Channel opened. [2020-02-24 14:03:37.6831] [DEBUG] Opened channel with endpoint ‘opc.tcp://192.168.1.120:4840’. [2020-02-24 14:03:37.6953] [DEBUG] [INTERNAL] Sending PublishRequest, Handle: 6 [2020-02-24 14:03:37.6988] [DEBUG] [INTERNAL] Sending ReadRequest, Handle: 7 [2020-02-24 14:03:37.7046] [DEBUG] [INTERNAL] Received ReadResponse, Handle: 7 Result: 0x00000000 [2020-02-24 14:03:37.7078] [INFO] 3:0001_Alarms= [2020-02-24 14:03:37.7078] [DEBUG] [INTERNAL] Sending ReadRequest, Handle: 8 [2020-02-24 14:03:37.7078] [DEBUG] [INTERNAL] Sending PublishRequest, Handle: 9 [2020-02-24 14:03:37.7078] [DEBUG] [INTERNAL] Sending PublishRequest, Handle: 10 [2020-02-24 14:03:37.7145] [DEBUG] [INTERNAL] Received ReadResponse, Handle: 8 Result: 0x00000000 [2020-02-24 14:03:37.7145] [INFO] 3:0002_State= [2020-02-24 14:03:37.7145] [DEBUG] [INTERNAL] Sending ReadRequest, Handle: 11 [2020-02-24 14:03:37.7248] [DEBUG] [INTERNAL] Received ReadResponse, Handle: 11 Result: 0x00000000 [2020-02-24 14:03:37.7248] [INFO] 3:0003_Mode= [2020-02-24 14:03:37.7248] [INFO] Created subscription. [2020-02-24 14:03:38.6809] [DEBUG] [INTERNAL] Received PublishResponse, Handle: 6 Result: 0x00000000 [2020-02-24 14:03:38.6855] [DEBUG] [INTERNAL] Sending PublishRequest, Handle: 12 [2020-02-24 14:04:08.6908] [DEBUG] [INTERNAL] Received PublishResponse, Handle: 9 Result: 0x00000000 [2020-02-24 14:04:08.6908] [DEBUG] [INTERNAL] Sending PublishRequest, Handle: 13 [2020-02-24 14:04:08.6970] [DEBUG] [INTERNAL] Received ServiceFault, Handle: 13 Result: 0x80270000 [2020-02-24 14:04:08.7014] [ERROR] [INTERNAL] Error publishing subscription. The session cannot be used because ActivateSession has not been called.

Do we do something wrong or is there a flaw in the client library? Any help is highly appreciated!

About this issue

Original URL
State: closed
Created 4 years ago
Comments: 19 (9 by maintainers)

Most upvoted comments

Yes, let me explain. The S7-1500 setting ‘Max session timeout’ is the number of seconds that a session connection may be unused before being closed by the server. In this version of firmware, the default timeout is 30 seconds (rather a short time). So, if a opc client does nothing with the connection for 30 seconds, the opc server will just close the connection. The UaTcpSessionChannel uses a background subscription as a keep-alive message. This subscription has a keep-alive interval of 30 seconds. Unfortunately the session timeout always won the battle and would close the connection. I plan to change this keep-alive interval to be 5 seconds, the same as UAExpert. This 5 second interval is only for the single internal subscription. Your subscriptions should use what is best for your program. The defaults will remain 30 secs for keep-alive, 3 * 30 seconds for lifetime.

awcullen on Mar 23, 2020

Ok. I reproduced the same issue. That’s the first step in fixing this!

awcullen on Mar 23, 2020

Well, I did try to catch this issue. Please set the LifetimeCount = 3 * MaxKeepAliveCount

// build a CreateSubscriptionRequest. See 'OPC UA Spec Part 4' paragraph 5.13.2
var req = new CreateSubscriptionRequest
{
    // the publish interval in milliseconds
    RequestedPublishingInterval = 1000.0, 
    // the number of publish intervals the server will wait to send an empty 'keep-alive' response
    RequestedMaxKeepAliveCount = 30,  
    // the number of publish intervals the server will wait to close the subscription
    RequestedLifetimeCount = 30 * 3,
    PublishingEnabled = true,
};

awcullen on Mar 22, 2020

To fix this issue, I will release a new version 2.5.2 in the coming days. To work around this issue today, you can changes the MaxSessionTimeout setting from 30 sec to 120 sec and download to your controller. Thanks again for reporting this issue.

awcullen on Mar 23, 2020

Would you share the firmware version of the S7-1500 controller. I’m using the S7-PLCSIM Advanced soft plc for testing. Knowing the firmware version will eliminate a variable in the testing.

awcullen on Mar 23, 2020

Hello @awcullen, thank you again for checking this issue. I ran some tests as promised, but I dont see any clearer. Maybe my understanding of the OpcUa system is not suffiecient, or the issue from @vladislav-mitev and me are not really identical und do only show the same symptoms.

My issue is the failure of the internal keep-alive subscription/state machine taks. I have checked the values in UaTcpSessionChannel you are using internally.

UaTcpSessionChannel.cs:

...
        public const double DefaultPublishingInterval = 1000f;
        public const uint DefaultKeepaliveCount = 30;
...
            // create the keep alive subscription.
            var subscriptionRequest = new CreateSubscriptionRequest
            {
                RequestedPublishingInterval = DefaultPublishingInterval,
                RequestedMaxKeepAliveCount = DefaultKeepaliveCount,
                RequestedLifetimeCount = DefaultKeepaliveCount * 3,
                PublishingEnabled = true,
            };

...

These are excatly the values suggested by you, so they should be “good” values according to the OpcUaStandard. However after 30 seconds of inactivity on the channel (no subscriptions, no read/write requests,…), I get the “Error publishing subscription” from the state machine tasks inside the UaTcpSessionChannel. I would expect the channel to be kept open, even when it is not used at the moment. Are my expectations wrong?

When I setup an subscription to a monitored item, using your suggested settings, neither subscription times out, but for this is more of a workaround.

I hope my description is not too confusing. Any help is highly appreceated.

Galama1979 on Mar 23, 2020

Well, I did try to catch this issue. Please set the LifetimeCount = 3 * MaxKeepAliveCount

// build a CreateSubscriptionRequest. See 'OPC UA Spec Part 4' paragraph 5.13.2
var req = new CreateSubscriptionRequest
{
    // the publish interval in milliseconds
    RequestedPublishingInterval = 1000.0, 
    // the number of publish intervals the server will wait to send an empty 'keep-alive' response
    RequestedMaxKeepAliveCount = 30,  
    // the number of publish intervals the server will wait to close the subscription
    RequestedLifetimeCount = 30 * 3,
    PublishingEnabled = true,
};

Thank you for your effort, I am back in the office and have access to the Siemens HW. I will let you know the results as soon as I ran some tests.

Galama1979 on Mar 23, 2020

I got as far as installing S7-PLCSIM Advanced and TIA Portal. Next, I need to set up a test to reproduce the issue. I want to thank you for all your work in finding a work around.

awcullen on Mar 18, 2020

The server is a Siemens Simatic S7-1500: https://www.siemens.com/s7-1500 In the provided logs above there is the status code of each Read response. However, reading of data and subscribing for data change events (CreateMonitoredItemsRequest) is OK, as we found that our identifier was wrong. However, the error persists.

We found that the error is affected by the KeepAliveCount setting on the subscription which we use for our CreateMonitoredItemsRequest. The error occurres for KeepAliveCount values: 20, 30, 31, 32, 33, 38, 45, 48 Everything is OK for KeepAliveCount values: 10, 25, 26, 27, 28, 29, 41, 49, 50, 74

Other subscription settings that we use: PublishingInterval=1000; LifetimeCount=30; PublishingEnabled=true.

UPDATE: Actually some “good” settings from above are also raising errors, but after a lot of time. So, for us the only known working configuration is: PublishingInterval=500; KeepAliveCount=10; LifetimeCount=30; PublishingEnabled=true.

vladislav-mitev on Mar 5, 2020