blocklayer bug and possible mishandling of duplicates

[PalmaITEM]

With intermittent connections, where duplicate requests end up being generated, the following happens: (client)

self._blockLayer.receive_response(transaction) File "/usr/local/lib/python2.7/dist-packages/coapthon/layers/blocklayer.py", line 182, in receive_response transaction.response.payload = self._block2_sent[key_token].payload + transaction.response.payload TypeError: cannot concatenate 'str' and 'NoneType' objects

This occurred using the forward proxy (with multiple simultaneous requests) and the problem seems to be, after correctly receiving the first block, the sending of a delayed response/ACK to the initial request but as if it was block 2 with 0 bytes:

(forward proxy)

2017-04-10 11:34:19,463 - MainThread - coapthon.forward_proxy.coap - DEBUG - receive_datagram - From ('a:1::10', 47197), To None, CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:19,463 - MainThread - coapthon.layers.messagelayer - DEBUG - receive_request - From ('a:1::10', 47197), To None, CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:19,464 - MainThread - coapthon.forward_proxy.coap - DEBUG - message duplicated,transaction completed 2017-04-10 11:34:19,464 - MainThread - coapthon.layers.messagelayer - DEBUG - send_response - From None, To ('a:1::10', 47197), ACK-21046, CONTENT-None, [Block2: 22, ] ...0 bytes 2017-04-10 11:34:19,473 - MainThread - coapthon.forward_proxy.coap - DEBUG - send_datagram - From None, To ('a:1::10', 47197), ACK-21046, CONTENT-None, [Block2: 22, ] ...0 bytes

More complete output from the client side:

2017-04-10 11:34:01,852 - MainThread - coapthon.layers.messagelayer - DEBUG - send_request - From None, To ('a:1::1', 5683), CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:01,855 - MainThread - coapthon.client.coap - DEBUG - send_datagram - From None, To ('a:1::1', 5683), CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:01,856 - Thread-1 - coapthon.client.coap - DEBUG - Start receiver Thread 2017-04-10 11:34:01,857 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - retransmit loop ... enter 2017-04-10 11:34:04,451 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - retransmit loop ... retransmit Request 2017-04-10 11:34:04,459 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - send_datagram - From None, To ('a:1::1', 5683), CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:09,647 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - retransmit loop ... retransmit Request 2017-04-10 11:34:09,653 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - send_datagram - From None, To ('a:1::1', 5683), CON-21046, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, ] No payload 2017-04-10 11:34:19,461 - Thread-1 - coapthon.client.coap - DEBUG - receive_datagram - From ('a:1::1', 5683), To None, ACK-21046, CONTENT-None, [Block2: 14, ] Lorem ipsum dolor si...1024 bytes 2017-04-10 11:34:19,461 - Thread-1 - coapthon.layers.messagelayer - DEBUG - receive_response - From ('a:1::1', 5683), To None, ACK-21046, CONTENT-None, [Block2: 14, ] Lorem ipsum dolor si...1024 bytes 2017-04-10 11:34:19,461 - Thread-1 - coapthon.client.coap - DEBUG - Waiting for retransmit thread to finish ... 2017-04-10 11:34:19,471 - Thread-1 - coapthon.client.coap - DEBUG - Waiting for retransmit thread to finish ... 2017-04-10 11:34:19,482 - Thread-1 - coapthon.client.coap - DEBUG - Waiting for retransmit thread to finish ... 2017-04-10 11:34:19,490 - MainThread-Retry-21046 - coapthon.client.coap - DEBUG - retransmit loop ... exit 2017-04-10 11:34:19,492 - Thread-1 - coapthon.layers.messagelayer - DEBUG - send_request - From None, To ('a:1::1', 5683), CON-None, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, Block2: 22, ] No payload 2017-04-10 11:34:19,498 - Thread-1 - coapthon.client.coap - DEBUG - send_datagram - From None, To ('a:1::1', 5683), CON-6285, GET-None, [Uri-Path: big, Proxy-Uri: coap://[a:2::20]:5683/big/, Block2: 22, ] No payload 2017-04-10 11:34:19,499 - Thread-1-Retry-6285 - coapthon.client.coap - DEBUG - retransmit loop ... enter 2017-04-10 11:34:19,500 - Thread-1 - coapthon.client.coap - DEBUG - receive_datagram - From ('a:1::1', 5683), To None, ACK-21046, CONTENT-None, [Block2: 22, ] No payload 2017-04-10 11:34:19,500 - Thread-1 - coapthon.layers.messagelayer - DEBUG - receive_response - From ('a:1::1', 5683), To None, ACK-21046, CONTENT-None, [Block2: 22, ] No payload Exception in thread Thread-1: ...

[danielwidmann]

@Tanganelli, could it be a race condition with the transaction.response field? At many places the response is initialized like this:

transaction.response = Response()
transaction.response.destination = transaction.request.source
transaction.response.token = transaction.request.token
transaction.response.code = defines.Codes.CONTINUE.number
transaction.response.block1 = (num, m, size)

Another thread could access the response before it is fully populated.

[Tanganelli]

Hi, I don't know honestly, I have to investigate it.