concurrent.futures._base.TimeoutError

[RensRoodt]

Hello All,

I'm using this python client, to connect with the a server on a PLC (beckhoff). when it runs for about a hour and 20 minutes, the client gets this error: Traceback (most recent call last): File "C:\Users\rens.op.het.rood\Desktop\Rens\ASML Softwarepack_01\GUI_ADS_OPCUA\SystemFunctions\GuiFunctions.py", line 953, in UpdateSystem self.ReadDasDigitalInfo() File "C:\Users\rens.op.het.rood\Desktop\Rens\ASML Softwarepack_01\GUI_ADS_OPCUA\SystemFunctions\GuiFunctions.py", line 1006, in ReadDasDigitalInfo result, TempCount = self.main.OpcUaConnect.get_value_WithNodeID(TmpAddr) File "C:\Users\rens.op.het.rood\Desktop\Rens\ASML Softwarepack_01\GUI_ADS_OPCUA\OPCUAInterface\UaClient.py", line 76, in get_value_WithNodeID value = var.get_value() File "C:\Python34\lib\site-packages\opcua\common\node.py", line 152, in get_value result = self.get_data_value() File "C:\Python34\lib\site-packages\opcua\common\node.py", line 161, in get_data_value return self.get_attribute(ua.AttributeIds.Value) File "C:\Python34\lib\site-packages\opcua\common\node.py", line 272, in get_attribute result = self.server.read(params) File "C:\Python34\lib\site-packages\opcua\client\ua_client.py", line 326, in read data = self._uasocket.send_request(request) File "C:\Python34\lib\site-packages\opcua\client\ua_client.py", line 78, in send_request data = future.result(self.timeout) File "C:\Python34\lib\concurrent\futures_base.py", line 404, in result raise TimeoutError() concurrent.futures._base.TimeoutError

In issue #526 this issue is discussed and a solution is provided: client = Client("<opc.tcp>", timeout=60*8) # 8 minutes

I tried this and the result is that the GUI (with OPC UA) freezes for 8 minutes, and then the same error appears. When I run the same test with the UA expert client the UA expert client stays connected. Do you guys have any idea in which direction I could look at to fixe this problem?

[libra146]

You need to give the smallest code that can reproduce the problem.

[oroulet]

The error means that the server does not answer within a sensible amount of time.... Either your have a bad network or a bad server. Or you also get another error message from server you have not reported

[RensRoodt]

@oroulet The weird thing is that with the UA Expert cliënt i don't get the same problem. On the server side there are no errors reported.

[oroulet]

Maybe there is another error before? Can it be that the session is closed due to another thing?

[RensRoodt]

@oroulet sorry for the late response. i dit some tests, there are no errors before it disconnects. this is the code it gets kicked off every two seconds:

var = self.client.get_node(Nodeid) value = var.get_value()

[visued]

I am the same problem... @RensRoodt you find solution for this? Here in UAExpert no problems...

[oroulet]

There are some error messages missing here. Can you record a session using wireshark until this happens? And put log here

[RensRoodt]

@visued no not yet, what kind of server are you using?

@oroulet yes i will run the test, However when i run the code now it does not connect i get this error: Traceback (most recent call last): File "C:/Users/rens.op.het.rood/Desktop/Rens/GU_OPCUA_bfsr/OPCUA_VS_ADS.py", line 50, in ConnectToPLC self.OpcUaConnect.Connect() File "C:\Users\rens.op.het.rood\Desktop\Rens\GU_OPCUA_bfsr\OPCUAInterface\UaClient.py", line 61, in Connect self.client.connect() File "C:\Python34\lib\site-packages\opcua\client\client.py", line 255, in connect self.open_secure_channel() File "C:\Python34\lib\site-packages\opcua\client\client.py", line 306, in open_secure_channel result = self.uaclient.open_secure_channel(params) File "C:\Python34\lib\site-packages\opcua\client\ua_client.py", line 254, in open_secure_channel return self._uasocket.open_secure_channel(params) File "C:\Python34\lib\site-packages\opcua\client\ua_client.py", line 184, in open_secure_channel future = self._send_request(request, message_type=ua.MessageType.SecureOpen) File "C:\Python34\lib\site-packages\opcua\client\ua_client.py", line 61, in _send_request self._request_id += 1 AttributeError: 'UASocketClient' object has no attribute '_request_id'

connecting with UA expert works, i tried different PLC to connect with and same result. Can you tell me what this error means? i can also make a different issue out of this?

[oroulet]

@RensRoodt I cannot understand that error can happen self._request_id is initiliazed to 0 in constructor so it exists. Are you using an old version? try to update

[oroulet]

these lines have not been changed since 2015... so there is something really strange going on...

[RensRoodt]

@oroulet i think it's my mistake, i tried running on the laptop of a college, and it works fine. So i will look into my code.

[RensRoodt]

@oroulet i found it made an typeO i will runn the test today with wireshark

[RensRoodt]

Here is the wireshark file. i couldn't export the file sow i converted it into an textfile. OPCUA WIRESHARK.txt

the lastmessage is an request for the read function, no response was given.

[oroulet]

txt is very hard to read.... you do not it to export, just save data then upload here diretly or as zip if you get issues

[RensRoodt]

20192406_CaptureFile_OPCUA.zip here is the zip file

[oroulet]

OK there is absoluetely no info in there, but it looks like the session timeout is set to one hour (3600s * 1000) but we do not see any session renewal call, so there is definitely an issue somewhere. Can you use python-opcya from master and hardcode some value there-: https://github.com/FreeOpcUa/python-opcua/blob/master/opcua/client/client.py#L58 set it to one hour (3600) and try. if it works, there is abug somewhere and a PR is welcome

[RensRoodt]

i've run the test i get the same problem

[okyame]

I have the same issue, I think it's because at line https://github.com/FreeOpcUa/python-opcua/blob/7e3140e6269be97e1a8c25802b0c913f0aace585/opcua/client/client.py#L63 this function doesn't manage to renew the connection.

[okyame]

We have this comment on this function : https://github.com/FreeOpcUa/python-opcua/blob/7e3140e6269be97e1a8c25802b0c913f0aace585/opcua/client/ua_client.py#L180

    def open_secure_channel(self, params):
        self.logger.info("open_secure_channel")
        request = ua.OpenSecureChannelRequest()
        request.Parameters = params
        future = self._send_request(request, message_type=ua.MessageType.SecureOpen)

        # FIXME: we have a race condition here
        # we can get a packet with the new token id before we reach to store it..
        response = struct_from_binary(ua.OpenSecureChannelResponse, future.result(self.timeout))
        response.ResponseHeader.ServiceResult.check()
        self._connection.set_channel(response.Parameters)
return response.Parameters

[okyame]

I have this variables values before and after renew:

In function https://github.com/FreeOpcUa/python-opcua/blob/7e3140e6269be97e1a8c25802b0c913f0aace585/opcua/client/client.py#L295

BEFORE RENEW

=>params value:

 OpenSecureChannelParameters(ClientProtocolVersion:0, RequestType:SecurityTokenRequestType.Issue, SecurityMode:MessageSecurityMode.SignAndEncrypt, ClientNonce:b'\xf4~>\x03\xa6\x97xx#\xf8\xbd\x1f\xac\x88\xc4\x17R\x17\x9d\xc3{\xa1\xfb\xc51\xa1\x14A\\\xa6{c', RequestedLifetime:3600000)

=>nonce value:

b'\xf4~>\x03\xa6\x97xx#\xf8\xbd\x1f\xac\x88\xc4\x17R\x17\x9d\xc3{\xa1\xfb\xc51\xa1\x14A\\\xa6{c'

=>Result value: 

OpenSecureChannelResult(ServerProtocolVersion:0, SecurityToken:ChannelSecurityToken(ChannelId:30, TokenId:14, CreatedAt:2019-06-26 10:55:08.781629, RevisedLifetime:3600000), ServerNonce:b'\xc3\xc3o\'#Gnip\xe7.D\x81\xd7W\xcb@m\x92N\xf5\xbf\x82\xffZ\x17"Y\xae\x16\xd0|')

=>self.security_policy value: 

<opcua.crypto.security_policies.SecurityPolicyBasic256Sha256 object at 0x7ff2e2939d68>

=>self.secure_channel_timeout value: 

3600000

AFTER RENEW

=>params value:

OpenSecureChannelParameters(ClientProtocolVersion:0, RequestType:SecurityTokenRequestType.Renew, SecurityMode:MessageSecurityMode.SignAndEncrypt, ClientNonce:b'`\x11"\xe8\xd0\x86p\x06\xb8x\x0b\xc8D\xc7\xf8\xc0\x9e\xf9h\xf5\xf8\xfc\xfb\xca\x02\x93\x7f\xbbUD\nN', RequestedLifetime:3600000)

=>nonce value:

 b'`\x11"\xe8\xd0\x86p\x06\xb8x\x0b\xc8D\xc7\xf8\xc0\x9e\xf9h\xf5\xf8\xfc\xfb\xca\x02\x93\x7f\xbbUD\nN'

=>Result value: 

OpenSecureChannelResult(ServerProtocolVersion:0, SecurityToken:ChannelSecurityToken(ChannelId:30, TokenId:15, CreatedAt:2019-06-26 10:55:28.825645, RevisedLifetime:3600000), ServerNonce:b'W\x9f\xe4A\x7f\x01\xab\\+\n\xa1v\xc4\x9b\x08\x9708\xc3\x83\xde\xd6\x94\xd8 f\xbfI>:\xec\xad')

=>self.security_policy value:  

<opcua.crypto.security_policies.SecurityPolicyBasic256Sha256 object at 0x7ff2e2939d68>

=>self.secure_channel_timeout value: 

3600000

[RensRoodt]

okee looks the same the result? or am i not seeing something?

[okyame]

I notice that the client nonce, the server nonce and the TokenId are different.

[okyame]

And after the renew, client can't contact the server anymore.

[oroulet]

Yes after renew the token and nonce stuff should be different. That stuff used to work, I should have a look. We are also using it...

[oroulet]

And we have beckoff PLC

[RensRoodt]

we are also using Beckhoff. okee thank you @oroulet

[RensRoodt]

i have run some tests again could it be that the "try" is not called.

def run(self): self.logger.debug("starting keepalive thread with period of %s milliseconds", self.timeout) server_state = self.client.get_node(ua.FourByteNodeId(ua.ObjectIds.Server_ServerStatus_State)) while not self._dostop: with self._cond: self._cond.wait(self.timeout / 1000) if self._dostop: break self.logger.debug("renewing channel") try: self.client.open_secure_channel(renew=True) except concurrent.futures.TimeoutError: self.logger.debug("keepalive failed: timeout on open_secure_channel()") break val = server_state.get_value() self.logger.debug("server state is: %s ", val) self.logger.debug("keepalive thread has stopped")

this is in the client.py

[okyame]

The "try" block is called. As I already said: the "self.client.open_secure_channel(renew=True)" function doesn't work fine.

[oroulet]

Add a bunch of print there or use pdb must be possible to understand what is happening

[oroulet]

I just tested locally and the renew stuff is called and channel is renewed