Unable to transfer large payload over MQTT over TLS using mbedtls

Tip / Sign in to post questions, reply, level up, and achieve exciting badges. Know more

cross mob
NiDa_4773006
Level 1
Level 1

I am trying to transfer a large file (~100kB) from our server over MQTT using mbedtls as TLS library. Any incoming/outgoing payloads that are less than the MTU (1500 bytes) transfers without error. Any incoming payloads greater than MTU result in TCP receive error. However, the exact same code downloading 9kB payloads from server via broker will succeed if verbose logging is enabled. The logging significantly slows the application.  Is there any special application considerations when downloading payload that are greater than MTU (ie require defragmentation buffer)? If required, I can provide wireshark captures.

Setup:

Custom board with CY8C6247BZI-D54

RTOS

Wiced SDK 6.4 running custom 43xx_Wi-Fi app

Netx Duo v5.10

Common Defines

#for reduction of RAM usage

WICED_CONFIG_DISABLE_SSL_SERVER

WICED_CONFIG_DISABLE_ENTERPRISE_SECURITY

WICED_CONFIG_DISABLE_ADVANCED_SECURITY_CURVES

#Error Logging

WPRINT_ENABLE_PLATFORM_ERROR

WPRINT_ENABLE_SECURITY_ERROR

WPRINT_ENABLE_NETWORK_ERROR

#TX/RX Pools / TCP

WICED_USE_COMMON_PKT_POOL

COM_PACKET_POOL_SIZE=20

WICED_TCP_WINDOW_SIZE=65535

Scenario 1 - Download 108kB file in multiple 9kB chunks, verbose logging off. Failed download of chunk

Following Error occurs:

mbedtls_ssl_read failed with error : [2]

[MQTT-LIB] TCP receive error 2

mbedtls_ssl_read failed with error : [2]

[MQTT-LIB] TCP receive error 2

mbedtls_ssl_read failed with error : [2]

[MQTT-LIB] TCP receive error 2

Scenario 2 - Download 108kB file in multiple 18kB chunks, verbose logging on. Failed download of chunk

Following Error occurs

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2798: => write record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:1310: => encrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:1615: <= encrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2487: => flush output

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2539: <= flush output

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2960: <= write record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7215: => read

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3834: => read record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 0, nb_want: 5

TLS library asked for [5] bytes

Received new TCP packet with length [1460]

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 0, nb_want: 5

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 0 (-0x0000)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2474: <= fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 5, nb_want: 16413

TLS library asked for [16408] bytes

Skip [5] no of bytes from TCP received packet with length : [1460]

Defragmentaion case : copying 1460 bytes to defrag buffer 0x0802aa30

Defrag buffer length [16413], [0] bytes processed, [0] skipped, [0] received

TLS record defragmentation failed with result : [2]

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 5, nb_want: 16413

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:4046: mbedtls_ssl_fetch_input() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3842: mbedtls_ssl_read_record_layer() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7314: mbedtls_ssl_read_record() returned 2 (-0xfffffffe)

mbedtls_ssl_read failed with error : [2]

[MQTT-LIB] TCP receive error 2

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7215: => read

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3834: => read record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 0, nb_want: 5

TLS library asked for [5] bytes

halfway TLS defrag ## defragmentation buffer bytes received [13140] total defragmentaion bytes [16413]

Already have [13140] bytes in defragmentation buffer, asked for [5]

defragmentation buffer bytes skipped [0]

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 0, nb_want: 5

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 0 (-0x0000)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2474: <= fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 5, nb_want: 16413

TLS library asked for [16408] bytes

halfway TLS defrag ## defragmentation buffer bytes received [13140] total defragmentaion bytes [16413]

halfway TLS record defragmentation failed with result : [2]

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 5, nb_want: 16413

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:4046: mbedtls_ssl_fetch_input() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3842: mbedtls_ssl_read_record_layer() returned 2 (-0xfffffffe)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7314: mbedtls_ssl_read_record() returned 2 (-0xfffffffe)

mbedtls_ssl_read failed with error : [2]

[MQTT-LIB] TCP receive error 2

Scenario 3 - Download 108kB file in multiple 9kB chunks, verbose logging on. Successful download chunks

Additional Defines:

MBEDTLS_MEMORY_DEBUG

MBEDTLS_DEBUG_C

MBEDTLS_SSL_DEBUG_ALL

MBEDTLS_DEBUG_LOG_LEVEL=2

WPRINT_ENABLE_SECURITY_INFO

WPRINT_ENABLE_SECURITY_DEBUG

WPRINT_ENABLE_NETWORK_DEBUG

Logs of successful chunk downloads:

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2798: => write record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:1310: => encrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:1615: <= encrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2487: => flush output

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2539: <= flush output

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2960: <= write record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7215: => read

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3834: => read record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 0, nb_want: 5

TLS library asked for [5] bytes

Received new TCP packet with length [1460]

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 0, nb_want: 5

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 0 (-0x0000)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2474: <= fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2263: => fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2429: in_left: 5, nb_want: 9079

TLS library asked for [9074] bytes

Skip [5] no of bytes from TCP received packet with length : [1460]

Defragmentaion case : copying 1460 bytes to defrag buffer 0x0802aa30

Defrag buffer length [9079], [0] bytes processed, [0] skipped, [0] received

Completed TLS record defragmentation. Received [9079] bytes

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2459: in_left: 5, nb_want: 9079

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2460: ssl->f_recv(_timeout)() returned 0 (-0x0000)

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2474: <= fetch input

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:1631: => decrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:2106: <= decrypt buf

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:3867: <= read record

WICED/security/BESL/mbedtls_open/library/ssl_tls.c:7514: <= read

Received all fragmented data of length [9079],Processed [1424], Packetize [1411] bytes and give it to application 

First chunk received: 1361 bytes at 90000 offset

Received all fragmented data of length [9079],Processed [2835], Packetize [1411] bytes and give it to application 

Chunk received: 1411 bytes at 91361 offset

Received all fragmented data of length [9079],Processed [4246], Packetize [1411] bytes and give it to application 

Chunk received: 1411 bytes at 92772 offset

Received all fragmented data of length [9079],Processed [5657], Packetize [1411] bytes and give it to application 

Chunk received: 1411 bytes at 94183 offset

Received all fragmented data of length [9079],Processed [7068], Packetize [1411] bytes and give it to application 

Chunk received: 1411 bytes at 95594 offset

Received all fragmented data of length [9079],Processed [8479], Packetize [1411] bytes and give it to application 

Chunk received: 1411 bytes at 97005 offset

Received all fragmented data of length [9079],Processed [9063], Packetize [584] bytes and give it to application 

Freeing defrag buffer...

Chunk received: 584 bytes at 98416 offset

-------------------Chunk Download complete----------------

Please let me know if there is anything else you need to help debug this problem.

Cheers,

Nick

0 Likes
3 Replies
Aditi_B
Moderator
Moderator
Moderator
500 replies posted 5 questions asked 250 replies posted

Hi,

Can you also provide the Wireshark capture logs?

Thanks

0 Likes
Aditi_B
Moderator
Moderator
Moderator
500 replies posted 5 questions asked 250 replies posted

Hi,

Can you also provide the application code? Which MQTT broker are you using?

I see in the scenario 2 that the verbose logging is on. Can you specify the level of logging?

Thanks

0 Likes
lock attach
Attachments are accessible only for community members.

Hello,

Can you also provide the application code? Which MQTT broker are you using?

We are using Mosquitto Broker using MQTT v3.1.1.

I see in the scenario 2 that the verbose logging is on. Can you specify the level of logging?

Scenario 2 and 3 have the same level of logging enabled.

Attached capture files show scenario 1 (failed_image_transfer - 9kb chunks, no logging) and scenario 3 (successful_image_transfer - 9kb chunks, verbose logging). The server is 192.162.1.170 and the client is 192.162.1.206.

We have currently found, and are going forward with a work around for this issue.

Our solution:

-Keep mqtt payloads under MTU to avoid using TLS defrag buffer.

-Implement defrag buffer in application space

-Reduction of MQTT QoS to 0, implement retries for missed packets in application space (for transfer speed purposes. Unknown if QoS contributed to above problem).

Result:

     -108kB image chunked into 80pieces (1350kB payload) transfers in 1-2s. This is acceptable for our application.

I am still curious if we can find a solution to the original problem.

Cheers,

Nick

0 Likes