I did some more testing and debugging. I set MAX_MESSAGE_SIZE to 16 and PREFERRED_BLOCK_SIZE to16.
Also changed BLOCKWISE_STATUS_LIFETIME to 30000 , so i get the message sooner.
I used a simple block transfer Get in Contiki
static void
res_get_handler(void *request, void *response, uint8_t *buffer, uint16_t preferred_size, int32_t *offset){
int32_t strpos = 0;
const char *msg = "abcdefghijklmnopqrstuvwxyz012345";
printf("offset1 = %d\n",*offset);
/* Check the offset for boundaries of the resource data. */
if(*offset >= 32) {
REST.set_response_status(response, REST.status.BAD_OPTION);
/* A block error message should not exceed the minimum block size (16). */
const char *error_msg = "BlockOutOfScope";
REST.set_response_payload(response, error_msg, strlen(error_msg));
return;
}
REST.set_response_payload(response, msg + *offset ,preferred_size);
/* IMPORTANT for chunk-wise resources: Signal chunk awareness to REST engine. */
*offset += preferred_size;
printf("offset2 = %d\n",*offset);
/* Signal end of resource representation. */
if(*offset >= strlen(msg)) {
*offset = -1;
}
}
Using Copper and node directly. Copper shows:
2.05 Content (Blockwise) (Download finished)
abcdefghijklmnopqrstuvwxyz012345
log from Copper:
INFO: Storing transaction 35405
=sending CoAP message===
Type: Confirmable
Code: GET
Message ID: 35405
Options:
Uri-Path: wishful_control [15]
Block2: 0/0/16 [0]
=======================
-sent UDP datagram------
Length: 22
-----------------------
-receiving UDP datagram-
Length: 24
-----------------------
=received CoAP message==
Type: Acknowledgment
Code: 2.05 Content
Message ID: 35405
Options:
Block2: 0/1/16 [1]
Payload: 16 bytes
abcdefghijklmnop
=======================
INFO: Closing message 35405
INFO: blockwiseHandler()
INFO: Storing transaction 35406
=sending CoAP message===
Type: Confirmable
Code: GET
Message ID: 35406
Options:
Uri-Path: wishful_control [15]
Block2: 1/0/16 [1]
=======================
-sent UDP datagram------
Length: 23
-----------------------
-receiving UDP datagram-
Length: 24
-----------------------
=received CoAP message==
Type: Acknowledgment
Code: 2.05 Content
Message ID: 35406
Options:
Block2: 1/0/16 [1]
Payload: 16 bytes
qrstuvwxyz012345
=======================
INFO: Closing message 35406
INFO: blockwiseHandler()
So Copper - node seems to work. I can't see anything wrong here.
Next with the proxy
===============
Copper shows:
2.05 Content (Blockwise) (Download finished)
abcdefghijklmnopqrstuvwxyz012345
Nov 16, 2015 2:42:59 PM org.eclipse.californium.proxy.resources.ProxyCoapClientResource forwardRequest
INFO: ProxyCoAP2CoAP forwards CON-GET MID=61946, Token=, OptionSet={"Uri-Path":"coap2coap", "Content-Format":"text/plain", "Block2":"(szx=0/16, m=false, num=0)", "Proxy-Uri":"coap://[aaaa::c30c:0:0:2]:5683/wishful_control"}, no payload
Nov 16, 2015 2:42:59 PM org.eclipse.californium.proxy.resources.ProxyCoapClientResource forwardRequest
INFO: ProxyCoapClient received CoAP request and sends a copy to CoAP target
Nov 16, 2015 2:43:29 PM org.eclipse.californium.core.network.stack.BlockwiseLayer$BlockCleanupTask run
INFO: Block2 transfer timed out: CON-GET MID=11716, Token=1135a2d2f9bd47c1, OptionSet={"Uri-Path":"wishful_control", "Content-Format":"text/plain"}, no payload
Copper Log
INFO: Storing transaction 61946
=sending CoAP message===
Type: Confirmable
Code: GET
Message ID: 61946
Options:
Uri-Path: coap2coap [9]
Content-Format: 0 [0]
Block2: 0/0/16 [0]
Proxy-Uri: coap://[aaaa::c30c:0:0:2]:5683/wishful_control [46]
=======================
-sent UDP datagram------
Length: 64
-----------------------
-receiving UDP datagram-
Length: 4
-----------------------
=received CoAP message==
Type: Acknowledgment
Code: EMPTY
Message ID: 61946
=======================
INFO: Closing message 61946
INFO: blockwiseHandler()
-receiving UDP datagram-
Length: 24
-----------------------
=received CoAP message==
Type: Confirmable
Code: 2.05 Content
Message ID: 35020
Options:
Block2: 0/1/16 [1]
Payload: 16 bytes
abcdefghijklmnop
=======================
INFO: Incoming separate reponse (Token: null)
=sending CoAP message===
Type: Acknowledgment
Code: EMPTY
Message ID: 35020
=======================
-sent UDP datagram------
Length: 4
-----------------------
INFO: blockwiseHandler()
INFO: Storing transaction 61947
=sending CoAP message===
Type: Confirmable
Code: GET
Message ID: 61947
Options:
Uri-Path: coap2coap [9]
Content-Format: 0 [0]
Block2: 1/0/16 [1]
Proxy-Uri: coap://[aaaa::c30c:0:0:2]:5683/wishful_control [46]
=======================
-sent UDP datagram------
Length: 65
-----------------------
-receiving UDP datagram-
Length: 24
-----------------------
=received CoAP message==
Type: Acknowledgment
Code: 2.05 Content
Message ID: 61947
Options:
Block2: 1/0/16 [1]
Payload: 16 bytes
qrstuvwxyz012345
=======================
INFO: Closing message 61947
INFO: blockwiseHandler()
The payload is shown correctly in Copper. But after 30 secs the console of the proxy will show the time out message.
But everything works if you just look at the output.
So i started debugging : org.eclipse.californium.core.network.stack.BlockwiseLayer
The class that generates the time out output
protected class BlockCleanupTask implements Runnable {
private Exchange exchange;
public BlockCleanupTask(Exchange exchange) {
this.exchange = exchange;
}
@Override
public void run() {
if (exchange.getRequest()==null) {
LOGGER.info("Block1 transfer timed out: " + exchange.getCurrentRequest());
} else {
LOGGER.info("Block2 transfer timed out: " + exchange.getRequest());
}
exchange.setComplete();
}
}
I have 2 theories
1) During the blockwise transfer there was a last message that was waiting for an ack or something.
Debugging in eclipse and wireshark i don't think that is the problem.. but i could have missed something
2) prepareBlockCleanup(exchange) is called when block transfer is used. Later when the exchange is complete the handler is set back to null.
public void sendResponse(Exchange exchange, Response response) {
....
if (status.isComplete()) {
// clean up blockwise status
LOGGER.fine("Ongoing finished on first block "+status);
exchange.setResponseBlockStatus(null);
exchange.setBlockCleanupHandle(null);
}
}
But does it remove the task? I dont know much about runnable and tasks in java so i might be way off here..
protected void prepareBlockCleanup(Exchange exchange) {
// prevent RejectedExecutionException
if (executor.isShutdown()) {
LOGGER.info("Endpoint is being destroyed: skipping block clean-up");
return;
}
BlockCleanupTask task = new BlockCleanupTask(exchange);
ScheduledFuture<?> f = executor.schedule(task , block_timeout, TimeUnit.MILLISECONDS);
exchange.setBlockCleanupHandle(f);
}
To reproduce.
1) contiki 3.0
2) examples/er-rest-example
3) CoAP server with a resource that implements the get method above
4) cf-proxy coap2coap resource