net_app DTLS Client net/pkt ERR log when doing handshake

[mazhenke]

Hi,

When I am using Zephyr to setup a DTLS Client, sometimes I saw the following [net/pkt] error message in bold text:

***** Booting Zephyr OS BUILD: Jul  5 2018 16:43:151.12.99 *****
[net/app] [INF] net_app_init: Initializing network
[net/app] [INF] setup_ipv4: IPv4 address: 192.168.1.111
[echo-client] [INF] init_app: Run echo client
[net/app] [DBG] _net_app_print_info: (0x2800fdb4): net app connect 192.168.1.111:46666 -> 192.168.1.103:4433
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800fdb4): Selecting 0x2800e36c net_ctx (net_app_connect():700)
[net/app] [DBG] tls_client_handler: (0x2800067c): Starting TLS client thread for 0x280005f8
[net/app] [DBG] _net_app_tls_init: (0x2800067c): SSL client setup done
[net/app] [DBG] connect_dtls: (0x2800fdb4): New DTLS connection context 0x2800e3b4 created
[net/app] [DBG] _net_app_ssl_mainloop: (0x2800067c): Starting TLS handshake
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013248
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013248 (len 88)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 60 bytes
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013248
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013248 (len 130)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 86 bytes
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 16 bytes
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013200
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013200 (len 53)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 25 bytes
**[net/pkt] [ERR] net_frag_read: Not enough data to read**
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013200
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013200 (len 42)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 14 bytes
**[net/pkt] [ERR] too_short_msg: udp data: IP hdr 20 ext len 0 offset 65535 pos 20 total 14**
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013248
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013248 (len 121)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 86 bytes
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 7 bytes
[net/app] [DBG] _net_app_ssl_mainloop: (0x2800067c): TLS handshake done
[net/app] [DBG] _net_app_ssl_mainloop: (0x2800067c): Calling connect cb for ctx 0x280005f8
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Sending plain data in pkt 0x28014058 (len 182)
[net/app] [DBG] _net_app_select_net_ctx_debug: (0x2800067c): Selecting 0x2800e3b4 net_ctx (net_app_get_net_pkt():972)
[net/app] [DBG] _net_app_dtls_established: (0x2800f9cc): Encrypted DTLS data received in pkt 0x28013248
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Receiving encrypted data in pkt 0x28013248 (len 281)
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 86 bytes
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 128 bytes
[net/app] [DBG] _net_app_ssl_mux: (0x2800067c): Copying all 39 bytes

I found this net/pkt ERR happens in function set_remote_endpoint, line: 1903, file: net_app.c
And also happens when doing the TLS handshake.
I guess when doing TLS handshake, there is no udp_hdr in pkt, causing the upper net/pkt ERR.

[pfalcon]

@mazhenke : Recently, DTLS socket support was merged: #9338 , and that's going to be the new official API for (D)TLS usage. You are thus recommended to switch to it whenever possible. You may find that older net_app DTLS client is in "maintenance mode" (that actually depends on developers' time availability, and AFAIK, they're fully occupied). I thus lower priority of this ticket.

[jukkar]

net-app API removed so this is no longer a valid issue