- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
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
- Labels:
-
Security
-
TCPIP
-
WICED Studio
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
Hi,
Can you also provide the Wireshark capture logs?
Thanks
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
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
- Mark as New
- Bookmark
- Subscribe
- Mute
- Subscribe to RSS Feed
- Permalink
- Report Inappropriate Content
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