Closed brubbel closed 4 years ago
Thanks for report. That stuff had been broken a few times. We should make the server really respect connection timeout and add tests for that
Also, along prev_security token, the previous symmetric decryption keys must be kept in order to make the transition between old and new keys work.
Can you make a PR? I never use antything alse then NoSecurity so I do not know much on that topic...
Background: When opening a secure channel, the server sends a
security_token.RevisedLifetime
to the client with valueparams.RequestedLifetime
. For UaExpert this is by default 3600 sec. https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L183Then after 3/4 of the RevisedLifetime (45 minutes by default), UaExpert will renew the secure channel (
SecurityTokenRequestType.Renew
). Which always fails and closes the connection if the client tries to communicate or when the subscription service tries to send an update to the client, whichever comes first. Problem:
- Renewal of the secure channel is first handled here, with a call to select_policy: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L323
- Select policy for an encrypted channel uses for example the policy factory SecurityPolicyBasic256Sha256 here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/crypto/security_policies.py#L518
which, in turn creates a new Cryptography instance here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/crypto/security_policies.py#L559
The Cryptography instance is initialized with Encryptor/Decryptor references set to None. However these Encryptor/Decryptor references will never be initialized here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L179-L194
because (a) the secure channel is in the open state and (b) the SecurityTokenRequestType is Renew. The following lines (required to initialize the Encryptor/Decryptor) are never called: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L188-L189
After that, any communication over the secure channel will fail when trying to access the required methods required for message_to_binary(). E.g. https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/crypto/security_policies.py#L125
Suggested solution: When a secure channel is in the
is_open()
state, never allow to callselect_policy()
again. Here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L323Possibly related:
845
Dear, would you please explain more about your Suggested solution? and if possible give an code example. Thank you in advance.
What you wrote make sense. PR welcome. I do not use encryption so I do not know well that code
Do you think that is possible to not renew the connection when client is asking for? Does the client still trust the connection if renewal won't happen?
Since I posted some stuff in the wrong place I will repeat it here.
I can reproduce the error by changing two parameters in UaExport:
Stack.SecureConnection_MinRevisedSecureChannelLifetime = 5000
General.SecureChannelLifetime = 5000
(First change MinRevisedSecureChannelLifetime
, then SecureChannelLifetime
)
When the failure occurs UaExpert does not register any errors. The values are just frozen without any sign the connection has crashed.
It takes ~20 seconds for the failure to occur. But if an item is being monitored it seems to be sooner.
Security: None + None
With security policy none
everything seems fine.
Security: Basic256sha256 + Sign
OPCUA master aed7ab0bbc8935a396b734634e378926a8dcbdf7
Creating an open endpoint to the server, although encrypted endpoints are enabled.
Tried to read attribute '10' in FourByteNodeId(i=2258), but the attribute is missing
Tried to read attribute '14' in TwoByteNodeId(i=35), but the attribute is missing
Tried to read attribute '15' in TwoByteNodeId(i=35), but the attribute is missing
Tried to read attribute '16' in TwoByteNodeId(i=35), but the attribute is missing
Tried to read attribute '14' in TwoByteNodeId(i=33), but the attribute is missing
Tried to read attribute '15' in TwoByteNodeId(i=33), but the attribute is missing
Tried to read attribute '16' in TwoByteNodeId(i=33), but the attribute is missing
Tried to read attribute '14' in TwoByteNodeId(i=31), but the attribute is missing
Tried to read attribute '15' in TwoByteNodeId(i=31), but the attribute is missing
Tried to read attribute '16' in TwoByteNodeId(i=31), but the attribute is missing
Tried to read attribute '14' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '15' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '16' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '10' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '14' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '15' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '16' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '10' in FourByteNodeId(i=2004), but the attribute is missing
Exception in callback InternalSubscription._sub_loop()
handle: <TimerHandle when=381454.619446846 InternalSubscription._sub_loop()>
Traceback (most recent call last):
File "/home/user/miniconda3/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 293, in _sub_loop
self.publish_results()
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 321, in publish_results
self.callback(result)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 80, in forward_publish_response
self.send_response(requestdata.requesthdr.RequestHandle, requestdata.seqhdr, response)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 47, in send_response
struct_to_binary(response), message_type=msgtype, request_id=seqhdr.RequestId)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 237, in message_to_binary
chunks = MessageChunk.message_to_chunks(self.security_policy, message, self._max_chunk_size, message_type=message_type, channel_id=self.security_token.ChannelId, request_id=request_id, token_id=self.security_token.TokenId)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 105, in message_to_chunks
max_size = MessageChunk.max_body_size(crypto, max_chunk_size)
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 81, in max_body_size
return max_plain_size - ua.SequenceHeader.max_size() - crypto.signature_size() - crypto.min_padding_size()
File "/home/user/Documents/python/opcua_test/dependencies/python-opcua/opcua/crypto/security_policies.py", line 153, in signature_size
return self.Signer.signature_size()
AttributeError: 'NoneType' object has no attribute 'signature_size'
Security: Basic256sha256 + Sign & Encrypt
Tested with 2 versions (master and last release):
OPCUA master: aed7ab0bbc8935a396b734634e378926a8dcbdf7
Tried to read attribute '14' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '15' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '16' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '10' in FourByteNodeId(i=2004), but the attribute is missing
Tried to read attribute '14' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '15' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '16' in TwoByteNodeId(i=58), but the attribute is missing
Tried to read attribute '10' in TwoByteNodeId(i=58), but the attribute is missing
Exception in callback InternalSubscription._sub_loop()
handle: <TimerHandle when=380808.40091346897 InternalSubscription._sub_loop()>
Traceback (most recent call last):
File "/home/user/miniconda3/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 293, in _sub_loop
self.publish_results()
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 321, in publish_results
self.callback(result)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 80, in forward_publish_response
self.send_response(requestdata.requesthdr.RequestHandle, requestdata.seqhdr, response)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 47, in send_response
struct_to_binary(response), message_type=msgtype, request_id=seqhdr.RequestId)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 237, in message_to_binary
chunks = MessageChunk.message_to_chunks(self.security_policy, message, self._max_chunk_size, message_type=message_type, channel_id=self.security_token.ChannelId, request_id=request_id, token_id=self.security_token.TokenId)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 105, in message_to_chunks
max_size = MessageChunk.max_body_size(crypto, max_chunk_size)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 80, in max_body_size
max_plain_size = (max_encrypted_size // crypto.encrypted_block_size()) * crypto.plain_block_size()
File "/home/user/opcua_test/dependencies/python-opcua/opcua/crypto/security_policies.py", line 126, in encrypted_block_size
return self.Encryptor.encrypted_block_size()
AttributeError: 'NoneType' object has no attribute 'encrypted_block_size'
OPCUA tag 0.98.12
This one seems more healthy without Tried to read attribute..
messages.
Exception in callback InternalSubscription._sub_loop()
handle: <TimerHandle when=380455.701013272 InternalSubscription._sub_loop()>
Traceback (most recent call last):
File "/home/user/miniconda3/lib/python3.7/asyncio/events.py", line 88, in _run
self._context.run(self._callback, *self._args)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 293, in _sub_loop
self.publish_results()
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/internal_subscription.py", line 321, in publish_results
self.callback(result)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 80, in forward_publish_response
self.send_response(requestdata.requesthdr.RequestHandle, requestdata.seqhdr, response)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/server/uaprocessor.py", line 47, in send_response
struct_to_binary(response), message_type=msgtype, request_id=seqhdr.RequestId)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 237, in message_to_binary
chunks = MessageChunk.message_to_chunks(self.security_policy, message, self._max_chunk_size, message_type=message_type, channel_id=self.security_token.ChannelId, request_id=request_id, token_id=self.security_token.TokenId)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 105, in message_to_chunks
max_size = MessageChunk.max_body_size(crypto, max_chunk_size)
File "/home/user/opcua_test/dependencies/python-opcua/opcua/common/connection.py", line 80, in max_body_size
max_plain_size = (max_encrypted_size // crypto.encrypted_block_size()) * crypto.plain_block_size()
File "/home/user/opcua_test/dependencies/python-opcua/opcua/crypto/security_policies.py", line 126, in encrypted_block_size
return self.Encryptor.encrypted_block_size()
AttributeError: 'NoneType' object has no attribute 'encrypted_block_size'
The renewal of encryption keys is indeed broken. Digging into the code I found that the transition between old en new keys is not working correctly, as both server and client must synchronize the transition (at one point you end up with both the old and new keys). The code needs some serious rework, but spare time is precious. :-)
The fix proposed by brubbel seems to work for me. I do not notice any other problems with transition to the new token.
I created a pull-request (https://github.com/FreeOpcUa/python-opcua/pull/1135). Is there any reason not to include it in the next release? (Even though it might not solve all the problems)
Great your analysis confirms my experience (Although I almost never use encryption)
Background: When opening a secure channel, the server sends a
security_token.RevisedLifetime
to the client with valueparams.RequestedLifetime
. For UaExpert this is by default 3600 sec. https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L183 Then after 3/4 of the RevisedLifetime (45 minutes by default), UaExpert will renew the secure channel (SecurityTokenRequestType.Renew
). Which always fails and closes the connection if the client tries to communicate or when the subscription service tries to send an update to the client, whichever comes first.Problem:
After that, any communication over the secure channel will fail when trying to access the required methods required for message_to_binary(). E.g. https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/crypto/security_policies.py#L125
Suggested solution: When a secure channel is in the
is_open()
state, never allow to callselect_policy()
again. Here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/common/connection.py#L323 and here: https://github.com/FreeOpcUa/python-opcua/blob/5bcb6820877db7f73d153430df2e1eedbca58b78/opcua/server/uaprocessor.py#L54Possibly related: https://github.com/FreeOpcUa/python-opcua/issues/845