Adaption to TCP+TLS on top of OpenThread.

[vipin das]

Hi All,

I am currently working on establishing a thread network to communicate to our http server:https://mainnet.incubed.net). In order to setting up that I took echo_client and http_client sample and adapted to our need. Below diagram is my network configuration with RPi connected with ethernet. 

I was successful in pinging the http server from thread network. Here I wanted to send TCP packets to remote server via OT network. 

I am novice to networking topics so it is really hard for me to understand and interpret the logs from the thread device. Below given is the log from the one node:

[00:00:00.396,331] <inf> ieee802154_nrf5: nRF5 802154 radio initialized
[00:00:00.396,728] <dbg> net_tcp: net_tcp_init: (main): Workq started. Thread ID: 0x20008378
[00:00:00.411,651] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.411,682] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.411,682] <inf> fs_nvs: data wra: 0, 0
[00:00:00.412,994] <inf> net_l2_openthread: State changed! Flags: 0x00038200 Current role: disabled
[00:00:00.418,487] <inf> net_config: Initializing network
[00:00:00.418,487] <inf> net_config: Waiting interface 1 (0x20000a08) to be up...
[00:00:30.419,189] <err> net_config: Timeout while waiting network interface
[00:00:30.419,219] <err> net_config: Network initialization failed (-115)
[00:00:30.419,525] <inf> in3_ot: Waiting for host to be ready to communicate
[00:00:30.423,675] <inf> usb_cdc_acm: Device suspended
[00:00:30.621,520] <inf> usb_cdc_acm: Device resumed
[00:00:30.737,701] <inf> usb_cdc_acm: Device suspended
[00:00:30.945,312] <inf> usb_cdc_acm: Device resumed
[00:00:31.006,927] <inf> usb_cdc_acm: Device configured
[00:00:44.243,072] <inf> net_l2_openthread: State changed! Flags: 0x00004000 Current role: disabled
[00:00:44.243,713] <inf> net_l2_openthread: State changed! Flags: 0x00020000 Current role: disabled
[00:00:44.243,804] <inf> net_l2_openthread: State changed! Flags: 0x00040000 Current role: disabled
[00:00:44.243,896] <inf> net_l2_openthread: State changed! Flags: 0x00000100 Current role: disabled
[00:00:44.247,131] <inf> net_l2_openthread: State changed! Flags: 0x00010000 Current role: disabled
[00:00:44.247,222] <inf> net_l2_openthread: State changed! Flags: 0x00008000 Current role: disabled
[00:00:44.247,741] <inf> net_l2_openthread: State changed! Flags: 0x10000000 Current role: disabled
[00:00:44.247,985] <inf> net_l2_openthread: State changed! Flags: 0x10000000 Current role: disabled
[00:00:44.249,053] <inf> net_l2_openthread: State changed! Flags: 0x00001000 Current role: disabled
[00:00:44.249,237] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.249,267] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.249,389] <inf> net_l2_openthread: State changed! Flags: 0x00000001 Current role: disabled
[00:00:44.249,450] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.249,542] <inf> net_l2_openthread: State changed! Flags: 0x00000008 Current role: disabled
[00:00:44.249,664] <inf> net_l2_openthread: State changed! Flags: 0x01000000 Current role: disabled
[00:00:44.249,786] <inf> net_l2_openthread: State changed! Flags: 0x00000004 Current role: detached
[00:00:44.249,938] <inf> net_l2_openthread: State changed! Flags: 0x00000001 Current role: detached
[00:00:44.250,030] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.250,152] <inf> net_l2_openthread: State changed! Flags: 0x00001000 Current role: detached
[00:00:44.250,274] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.250,396] <inf> net_l2_openthread: State changed! Flags: 0x00001000 Current role: detached
[00:00:44.250,549] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:44.250,640] <inf> net_l2_openthread: State changed! Flags: 0x00000010 Current role: detached
[00:00:44.251,373] <inf> net_l2_openthread: State changed! Flags: 0x10000000 Current role: detached
[00:00:46.497,467] <inf> net_l2_openthread: State changed! Flags: 0x200012a4 Current role: child
[00:00:46.497,741] <inf> net_l2_openthread: State changed! Flags: 0x00000001 Current role: child
[00:00:46.497,863] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:46.497,894] <wrn> net_l2_openthread: No address info provided with event, please enable CONFIG_NET_MGMT_EVENT_INFO
[00:00:46.497,955] <dbg> in3_ot: ping_send: Ping Server:
[00:00:46.497,985] <dbg> in3_ot: print_ipv6_address: Mesh Local EID Address: fd97.6739.093e.0002.0000.0000.a756.5ef8
[00:00:46.498,596] <dbg> in3_ot: ping_send: ping send response:0
[00:00:46.498,626] <dbg> main: main: Connected to thread network
[00:00:46.499,145] <dbg> net_tcp: tcp_conn_ref: (main): conn: 0x20033d58, ref_count: 1
[00:00:46.499,176] <dbg> net_tcp: tcp_conn_alloc: (main): conn: 0x20033d58
[00:00:46.499,389] <dbg> net_tcp: net_tcp_connect: (main): context: 0x20013814, local: ::, remote: fd97:6739:93e:2::a756:5ef8
[00:00:46.499,542] <dbg> net_tcp: net_tcp_connect: (main): conn: 0x20033d58 src: fd11:22::271f:b127:ea60:6f99, dst: fd97:6739:93e:2::a756:5ef8
[00:00:46.499,664] <dbg> net_tcp: tcp_in: (main):  [LISTEN Seq=1723021025 Ack=0]
[00:00:46.499,938] <dbg> net_tcp: tcp_out_ext: (main): SYN Seq=1723021025 Len=0
[00:00:46.500,091] <dbg> net_tcp: tcp_send_process_no_lock: (main): SYN Seq=1723021025 Len=0 
[00:00:46.500,305] <dbg> net_tcp: tcp_send: (main): SYN Seq=1723021025 Len=0
[00:00:46.500,671] <dbg> net_tcp: tcp_in: (main): LISTEN->SYN_SENT
[00:00:46.567,230] <dbg> net_tcp: tcp_in: (rx_q[0]): ACK,RST Seq=0 Ack=1723021026 Len=0 [SYN_SENT Seq=1723021026 Ack=0]
[00:00:46.567,260] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN_SENT->CLOSED
[00:00:46.567,352] <dbg> net_tcp: tcp_conn_unref_debug: (rx_q[0]): conn: 0x20033d58, ref_count=1 (tcp_in():2513)
[00:00:46.567,382] <dbg> net_tcp: tcp_conn_unref_debug: (rx_q[0]): conn: 0x20033d58 is waiting on connect semaphore
[00:00:46.573,516] <dbg> in3_ot: ping_reply_cb: Ping reply
[00:00:46.573,547] <dbg> in3_ot: print_ipv6_address: Mesh Local EID Address: fd97.6739.093e.0002.0000.0000.a756.5ef8

Can someone tell me what is happening here and what I did wrong or not taken into my consideration. 

Regards

Vipin Das

[Marte Myrvold]

Hi,

vipin das said:

You can share me any proper TLS sample where I can take a look and get inspired to make my application working 

The examples you used previously, echo_client and http_client, have support for enabling TLS by setting OVERLAY_CONFIG to overlay-tls.conf. Other than that, we also have support for Mbed TLS in several nRF9160 samples, such as HTTPS Client and Simple MQTT, and we have Crypto: PSA TLS that shows how to do TLS handshakes.

Best regards,

Marte

[vipin das]

Hi Marte, 

Any clue on TLS socket connection returns error -22?

I  took a look at the nRF9160 DK HTTPS Client sample and addd the missing config options but that also doesn't help to solve that error. 

Should I have to try anything else. 

Regards

Vipin Das

[Marte Myrvold]

Hi,

Error 22 is invalid argument, so most likely, one or more of the arguments you are giving is incorrect. You should check that the address length is valid for the address family and that the address family is correct.

Best regards,
Marte

[vipin das]

Hi Marte, 

I checked the address family and the address length but I don't see any potential issues. 

Now  I am using  getaddrinfo() to properly point the sockaddr and ensure there is no issue in address family and length. Below given my modification wrt to those change. 

#if defined(CONFIG_NET_SOCKETS_SOCKOPT_TLS)
  struct addrinfo hints = {
      .ai_family   = PF_INET6,
      .ai_socktype = SOCK_STREAM,
      .ai_protocol = IPPROTO_TLS_1_2,
      .ai_flags    = AI_NUMERICSERV | AI_NUMERICHOST | AI_V4MAPPED | AI_ALL};
  ret = getaddrinfo(SERVER_ADDR6, "443", &hints, &res);
#else
  struct addrinfo hints = {
      .ai_family   = AF_INET,
      .ai_socktype = SOCK_STREAM,
      .ai_protocol = IPPROTO_TCP,
      .ai_flags    = AI_NUMERICSERV | AI_NUMERICHOST | AI_V4MAPPED | AI_ALL};
  ret   = getaddrinfo(SERVER_ADDR6, "80", &hints, &res);
#endif

Still the result is same. 

[00:00:47.346,984] <dbg> http_client: establish_connection: ai_family: 2 ai_socktype: 1 ai_protocol: 6 ai_addrlen: 24
[00:00:47.347,137] <dbg> net_sock_tls: tls_alloc: (main): Allocated TLS context, 0x20003478
[00:00:47.347,473] <dbg> net_tcp: tcp_conn_ref: (main): conn: 0x20022520, ref_count: 1
[00:00:47.347,503] <dbg> net_tcp: tcp_conn_alloc: (main): conn: 0x20022520
[00:00:47.347,564] <dbg> net_sock: zsock_socket_internal: (main): socket: ctx=0x2001031c, fd=1
[00:00:47.347,747] <dbg> net_ctx: net_context_bind: (main): Context 0x2001031c binding to TCP [::]:50680 iface 1 (0x20000a98)
[00:00:47.347,839] <dbg> net_tcp: net_tcp_connect: (main): context: 0x2001031c, local: ::, remote: fd97:6739:93e:2::a756:5ef8
[00:00:47.348,022] <dbg> net_tcp: net_tcp_connect: (main): conn: 0x20022520 src: fd97:6739:93e:1:55e8:b55b:6c94:71e2, dst: fd97:6739:93e:2::a756:5ef8
[00:00:47.348,175] <dbg> net_conn: conn_register_debug: (main): [0x200107b8/6/2/0x3f] remote fd97:6739:93e:2::a756:5ef8/443 
[00:00:47.348,205] <dbg> net_conn: conn_register_debug: (main):   local ::/50680 cb 0x16e69 ud 0x2001031c
[00:00:47.348,358] <dbg> net_tcp: tcp_in: (main):  [LISTEN Seq=1876970369 Ack=0]
[00:00:47.348,602] <dbg> net_tcp: tcp_out_ext: (main): SYN Seq=1876970369 Len=0
[00:00:47.348,754] <dbg> net_tcp: tcp_send_process_no_lock: (main): SYN Seq=1876970369 Len=0 
[00:00:47.348,968] <dbg> net_tcp: tcp_send: (main): SYN Seq=1876970369 Len=0
[00:00:47.349,700] <dbg> net_tcp: tcp_in: (main): LISTEN->SYN_SENT
[00:00:47.412,445] <dbg> net_conn: net_conn_input: (rx_q[0]): Check TCP listener for pkt 0x200218d0 src port 443 dst port 50680 family 2
[00:00:47.412,506] <dbg> net_conn: net_conn_input: (rx_q[0]): [0x200107b8] match found cb 0x16e69 ud 0x2001031c rank 0x3f
[00:00:47.412,811] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN,ACK Seq=4052061474 Ack=1876970370 Len=0 [SYN_SENT Seq=1876970370 Ack=0]
[00:00:47.412,872] <dbg> net_tcp: tcp_options_check: (rx_q[0]): len=4
[00:00:47.412,902] <dbg> net_tcp: tcp_options_check: (rx_q[0]): opt: 2, opt_len: 4
[00:00:47.412,902] <dbg> net_tcp: tcp_options_check: (rx_q[0]): MSS=1460
[00:00:47.412,933] <dbg> net_tcp: tcp_in: (rx_q[0]): Lowering send window from 64240 to 1280
[00:00:47.412,963] <dbg> net_tcp: tcp_window_full: (rx_q[0]): conn: 0x20022520 window_full=0
[00:00:47.413,146] <dbg> net_tcp: tcp_send_timer_cancel: (rx_q[0]): SYN Seq=1876970369 Len=0
[00:00:47.413,452] <dbg> net_tcp: tcp_out_ext: (rx_q[0]): ACK Seq=1876970370 Ack=4052061475 Len=0
[00:00:47.413,635] <dbg> net_tcp: tcp_send_process_no_lock: (rx_q[0]): ACK Seq=1876970370 Ack=4052061475 Len=0 
[00:00:47.413,818] <dbg> net_tcp: tcp_send: (rx_q[0]): ACK Seq=1876970370 Ack=4052061475 Len=0
[00:00:47.413,940] <dbg> net_tcp: tcp_in: (rx_q[0]): SYN_SENT->ESTABLISHED
[00:00:47.414,154] <dbg> net_tcp: net_tcp_connect: (main): conn: 0x20022520, ret=0
[00:00:47.414,215] <dbg> net_tcp: net_tcp_recv: (main): context: 0x2001031c, cb: 0x8b81, user_data: (nil)
[00:00:47.425,842] <err> http_client: Cannot connect to IPv6 remote (-22)
[00:00:47.425,842] <err> http_client: Setup socket Failed
[00:00:47.425,842] <err> http_client: Failed to connect to socket

Do you have any thoughts or any further suggestions on this issue. 

Regards

Vipin Das