Block-wise transfer with PUT operation resulted in 5.00 response code in ACK

jqiaobln commented 2 years ago

Environment

libcoap version (run git describe --tags to find it): v4.3.0-57-gdf9071c
Build System: Make
Operating System: Linux
Operating System Version: 20.04
Hosted Environment: None

Problem Description

libcoap was receiving a block-wise transfer in octet stream format, PUT operation, from Califormium CoAP server. Block-wise transfer failed.

Expected Behavior

Every block is acked with success code and the whole file is received successfully.

Actual Behavior

1st block is acked with code 2.31, however 2nd block is acked with 5.00. libcoap is stalled after the 2nd ACK until the DTLS session was terminated by the peer.

Steps to reproduce

Start a libcoap instance with server support, block transfer option is default;
Let Califormium server initiated a PUT operation with an input file

Code to reproduce this issue

v4.3.0-57-gdf9071c code

Debug Logs

v:1 t:CON c:PUT i:3be3 {1035dd0e44f325d7} [ Uri-Path:example_data, Content-Format:application/octet-stream, Block1:0/M/512, Size1:4096 ] :: binary data length 512

v:1 t:ACK c:2.31 i:3be3 {1035dd0e44f325d7} [ Block1:0/M/512 ]

v:1 t:CON c:PUT i:3be4 {1035dd0e44f325d7} [ Uri-Path:example_data, Content-Format:application/octet-stream, Block1:1/M/512 ] :: binary data length 512

v:1 t:ACK c:5.00 i:3be4 {1035dd0e44f325d7} [ Block1:1/M/512 ]

Other items if possible

I'm trying the PR#740 code which you mentioned in a few other tickets that have fixed block transfer issues. However it doesn't seem to pick up any cipher suites from mbedtls. I'm running mbedtls 3.0.0. Also tried mbedtls 2.21, same issue.

mrdeep1 commented 2 years ago

I am unable to reproduce this (but am emulating the californium client to produce exactly the PDU information as you reported)

Dec 01 13:44:47.096 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: received 576 bytes
v:1 t:CON c:PUT i:0cbf {1035dd0e44f325d7} [ Uri-Path:example_data, Content-Format:application/octet-stream, Block1:0/M/512, Size1:4096 ] :: binary data length 512

Dec 01 13:44:47.096 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: sent 44 bytes
v:1 t:ACK c:2.31 i:0cbf {1035dd0e44f325d7} [ Block1:0/M/512 ]

Dec 01 13:44:47.096 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: received 576 bytes
v:1 t:CON c:PUT i:0cc0 {1035dd0e44f325d7} [ Uri-Path:example_data, Content-Format:application/octet-stream, Block1:1/M/512, Size1:4096 ] :: binary data length 512

Dec 01 13:44:47.097 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: sent 44 bytes
v:1 t:ACK c:2.31 i:0cc0 {1035dd0e44f325d7} [ Block1:1/M/512 ]

Dec 01 13:44:47.097 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: received 576 bytes
v:1 t:CON c:PUT i:0cc1 {1035dd0e44f325d7} [ Uri-Path:example_data, Content-Format:application/octet-stream, Block1:2/M/512, Size1:4096 ] :: binary data length 512

Dec 01 13:44:47.097 DEBG *  [::ffff:127.0.0.1]:5684 <-> [::ffff:127.0.0.1]:42716 (if1) DTLS: sent 44 bytes
v:1 t:ACK c:2.31 i:0cc1 {1035dd0e44f325d7} [ Block1:2/M/512 ]

etc.

Is your server only recieving one request at a time from a client? Are you doing this with the standard examples coap-server or is it a bespoke server? If standard example coap-server, can you run it with the -L3 option to see if this fixes the issue. It is unlikely that the libcoap code is generating the 5.00 code as most of the cases resport a diagnostic message as well, so my suspicion is with the server code.

However it doesn't seem to pick up any cipher suites from mbedtls. I'm running mbedtls 3.0.0. Also tried mbedtls 2.21, same issue

So, is the output reported above from when using DTLS or not? My suspicion here is that libcoap (with Mbed TLS)/californium cannot agree on a common cipher suite. It would be helpful for the coap-server to be run with full logging (-v9) for a single PUT session from the client to determine what the issues are likely to be and hence the direction to troubleshoot.

jqiaobln commented 2 years ago

Am using the standard example coap-server. After adding the -L3 option, block transfer worked. What does this option do?

jqiaobln commented 2 years ago

The log above is from running the v4.3.0-57-gdf9071 code. However the cipher suite issue only occurred when I tried to run your code of PR#740. Below is the log output from a client hello from running PR740; the bolded portion shows 0 cipher suite is selected; normally there are at least a dozen:

=======================================================================================

Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1056: client hello, session id len.: 0 Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1057: dumping 'client hello, session id' (0 bytes) Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1087: dumping 'client hello, cookie' (32 bytes) Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1087: 0000: 43 66 fc 81 98 00 e0 09 9c 33 b0 52 6b f8 02 d9 Cf.......3.Rk... Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1087: 0010: d1 d3 2c 89 27 44 c2 68 5a 5d 90 5a cf f5 8b f2 ..,.'D.hZ].Z.... Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1138: client hello, got 0 ciphersuites (excluding SCSVs) Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1148: adding EMPTY_RENEGOTIATION_INFO_SCSV Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1158: client hello, compress len.: 1 Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1159: client hello, compress alg.: 0 Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:0105: client hello, adding server name extension: coap-lb-na.play.test.cc Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:0223: client hello, adding signature_algorithms extension Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:0560: client hello, adding encrypt_then_mac extension Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:0590: client hello, adding extended_master_secret extension Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:0621: client hello, adding session ticket extension Nov 29 15:08:26.817 CIPH /home/CoAP/mbedtls/library/ssl_cli.c:1307: client hello, total extension length: 73

mrdeep1 commented 2 years ago

Am using the standard example coap-server. After adding the -L3 option, block transfer worked. What does this option do?

As per coap-server(5), -L3 is setting COAP_BLOCK_SINGLE_BODY which means as per coap_block(3) that the blocked transfer is all handled by libcoap, rather than in part by the application.

Below is the log output from a client hello from running PR740;

PR740 does not update the Mbed TLS shim file src/coap_mbedtls.c or the (D)TLS shim file src/coap_dtls.c so it makes no sense that Mbed TLS works with the develop branch, but not with PR740 as what you are seeing is in the initial client setup before any data is transferred. Are you sure that you have an up-to-date version of PR740?

5.00 error

What options are you using when running coap-server and things work as expected?
Are you trying to do this with (D)TLS?

All I can find is that if the underlying TLS libary fails to correctly support SHA256, then I can find a path throught the code that may explain what you are seeing.

When testing code with mbedtls on my ubuntu20 system, I am using sudo apt-get install -y libmbedtls-dev version of libmbedtls-dev and it all works fine.

mrdeep1 commented 2 years ago

There is a fix in PR #784 which may fix your 5.00 issue. Can you please try this out? Also, do you get any other debug messages just before the 5.00 is sent?

mrdeep1 commented 2 years ago

@jqiaobln Please free to re-open this issue if there still is a problem.

obgm / libcoap