Secure channel and renewal clarification

[RakshanPremsagar]

Hi Kevin,

Question is regarding the secure channel requirement for the registration of the OPC UA server with the discovery server. From the spec, I understand that for a registration, a secure channel has to be established. Also, a secure channel has to be having a security token

To have the registration, the client opens a secure channel. I have configured to have a channel time of 10 mins and also token lifetime to be 10mins. The server registers to the LDS every 5 mins.

Now what i observe is that, sometimes the secure channel gets renewed with revised lifetime more than 2 times, and sometimes just once.Is this renewal dependent on anything specific. I believe it should depend on the token lifetime which specification says starts to claim a new one upon 75% of its completion time. If that is the case, should it not continue with the same secure channel throughout revising itself?

Well, I have observations wrt to the open62541 stack. However, this I believe is more of OPC UA than the stack

[2021-02-12 21:37:26.120 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 2 | SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2021-02-12 21:37:26.120 (UTC+0100)] �[32minfo/client�[0m	Client Status: ChannelState: Open, SessionState: Closed, ConnectStatus: Good
[2021-02-12 21:37:26.120 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 21:42:26.125 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 21:42:26.125 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 21:47:26.128 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 21:47:26.128 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 2 | SecureChannel renewed with a revised lifetime of 600.00s
[2021-02-12 21:47:26.128 (UTC+0100)] �[33mwarn/channel�[0m	Connection 5 | SecureChannel 2 | Receiving the response failed with StatusCode BadConnectionClosed
[2021-02-12 21:47:26.129 (UTC+0100)] �[32minfo/client�[0m	Client Status: ChannelState: Closed, SessionState: Closed, ConnectStatus: Good
[2021-02-12 21:47:26.129 (UTC+0100)] �[31merror/client�[0m	RegisterServer/RegisterServer2 failed with statuscode BadConnectionClosed
[2021-02-12 21:47:26.129 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 3 | SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2021-02-12 21:47:26.129 (UTC+0100)] �[32minfo/client�[0m	Client Status: ChannelState: Open, SessionState: Closed, ConnectStatus: Good
[2021-02-12 21:47:26.129 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 21:52:26.131 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 21:52:26.131 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 21:57:26.134 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 21:57:26.134 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 3 | SecureChannel renewed with a revised lifetime of 600.00s
[2021-02-12 21:57:26.134 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 22:02:26.138 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 22:02:26.139 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds
[2021-02-12 22:07:26.142 (UTC+0100)] �[33mwarn/client�[0m	Client already connected
[2021-02-12 22:07:26.142 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 3 | SecureChannel renewed with a revised lifetime of 600.00s
[2021-02-12 22:07:26.143 (UTC+0100)] �[33mwarn/channel�[0m	Connection 5 | SecureChannel 3 | Receiving the response failed with StatusCode BadConnectionClosed
[2021-02-12 22:07:26.143 (UTC+0100)] �[32minfo/client�[0m	Client Status: ChannelState: Closed, SessionState: Closed, ConnectStatus: Good
[2021-02-12 22:07:26.143 (UTC+0100)] �[31merror/client�[0m	RegisterServer/RegisterServer2 failed with statuscode BadConnectionClosed
[2021-02-12 22:07:26.143 (UTC+0100)] �[32minfo/channel�[0m	Connection 5 | SecureChannel 4 | SecureChannel opened with SecurityPolicy http://opcfoundation.org/UA/SecurityPolicy#None and a revised lifetime of 600.00s
[2021-02-12 22:07:26.143 (UTC+0100)] �[32minfo/client�[0m	Client Status: ChannelState: Open, SessionState: Closed, ConnectStatus: Good
[2021-02-12 22:07:26.143 (UTC+0100)] �[32minfo/server�[0m	Server successfully registered. Next periodical register will be in 300 seconds





Does the "Receiving the response failed with StatusCode BadConnectionClosed" mean the token was not mutually accepted by both client and server?

Regards,
Rakshan

[kevinherron]

The renewal should only occur at 75% the negotiated channel lifetime. It might be interesting to capture this on Wireshark and see what's happening as well.

I'm not sure how much more help I can be, though, since I'm not very familiar with the Open62541 stack or codebase. The duplicate "periodical register" messages happening within the same ~1s do seem wrong to me.