mqtt_connect, error: -11 #83489

zafersn · 2025-01-02T03:17:47Z

zafersn
Jan 2, 2025

My application was working with zephyrV3.6-Branch revision. I tested my app with zephyr4.0-Branch and getting this error now:
mqtt_connect, error: -11
[00:02:23.171,000] aws_iot: AWS broker connect failed -11

just before failing: zsock_connect return -1.

ret = zsock_connect(client->transport.tls.sock, client->broker,
			    peer_addr_size);
	if (ret < 0) {
		printk("%d %s %d\n", __LINE__, __func__, ret);

		goto error;
	}

Can anyone please help on this.

here is full log:

[00:01:05.920,000] <dbg> modem_hl7800: offload_get: offload_get
[00:01:05.920,000] <dbg> modem_hl7800: offload_get: 4079 hl7800.c 1
[00:01:05.920,000] <dbg> modem_hl7800: set_busy: 0 called: 4096
[00:01:05.920,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4097
[00:01:05.920,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
47 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
55 mqtt_client_tls_connect
64 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
73 mqtt_client_tls_connect
84 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
95 mqtt_client_tls_connect
112 mqtt_client_tls_connect 8 1
[00:01:05.920,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:05.920,000] <dbg> modem_hl7800: offload_bind: offload_bind
[00:01:05.920,000] <dbg> modem_hl7800: offload_connect: offload_connect
4163 offload_connect
4174 offload_connect
4195 offload_connect
4200 offload_connect
[00:01:05.920,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4204
[00:01:05.920,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:05.920,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:05.920,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:05.920,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:05.920,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
4205 offload_connect
[00:01:05.920,000] <dbg> modem_hl7800: offload_connect: Socket not created, configuring TCP socket
[00:01:05.920,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCFG=1,0,"34.247.3.59",8883,,,,0,,0]
[00:01:05.924,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
+KTCPCFG: 2
3977 hl.c 11 |+KTCPCFG: 2|
[00:01:05.944,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCPCFG: 2
[00:01:05.944,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCPCFG:  (len:1)
[00:01:05.944,000] <dbg> modem_hl7800_rx: on_cmd_sockcreate: +KTCPCFG: 2
[00:01:05.944,000] <dbg> modem_hl7800_rx: on_cmd_sockcreate: no sock, look up new socket by creation id
OK
[00:01:05.944,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
4216 offload_connect 0
[00:01:06.206,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCNX=2]
[00:01:06.207,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:06.231,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
+KTCP_IND: 2,1
3977 hl.c 14 |+KTCP_IND: 2,1|
[00:01:07.072,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_IND: 2,1
[00:01:07.072,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_IND:  (len:3)
[00:01:07.072,000] <dbg> modem_hl7800_rx: on_cmd_sock_ind: +KTCP_IND ID: 2
4229 offload_connect 0
[00:01:07.129,000] <dbg> modem_hl7800: set_busy: 0 called: 4230
[00:01:07.129,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4231
[00:01:07.130,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
4238 offload_connect 0
256 z_impl_zsock_connect: 0 0
z_impl_zsock_connect: 0 0
[00:01:07.153,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:07.153,000] <dbg> modem_hl7800: offload_send: offload_send
[00:01:07.153,000] <dbg> modem_hl7800: offload_sendto: offload_sendto
[00:01:07.153,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4300
[00:01:07.153,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:07.153,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:07.153,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:07.153,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:07.153,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:07.153,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPSND=2,131]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:07.165,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:07.165,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:07.289,000] <dbg> modem_hl7800: send_data: Sent 131 bytes
OK
[00:01:07.295,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:07.295,000] <dbg> modem_hl7800: set_busy: 0 called: 4306
[00:01:07.295,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4307
[00:01:07.295,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
345 z_impl_zsock_sendto: 131 0
487 z_impl_zsock_recvfrom: -1 11
+KTCP_DATA: 2,1424
3977 hl.c 18 |+KTCP_DATA: 2,1424|
[00:01:09.177,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,1424
[00:01:09.177,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:6)
[00:01:09.177,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:09.177,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:09.177,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:09.177,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:09.177,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:09.177,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:09.177,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:1424
[00:01:09.177,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,1424]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:09.188,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:09.188,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:09.188,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 1424 bytes
[00:01:09.188,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.239,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 579
[00:01:09.241,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:579
[00:01:09.241,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.293,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:1181
[00:01:09.293,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.344,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:09.344,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:09.344,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:09.344,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:09.344,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:09.344,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 1464)
487 z_impl_zsock_recvfrom: 5 11
487 z_impl_zsock_recvfrom: 85 11
487 z_impl_zsock_recvfrom: 5 11
487 z_impl_zsock_recvfrom: 1329 11
487 z_impl_zsock_recvfrom: -1 11
+KTCP_DATA: 2,1424
3977 hl.c 18 |+KTCP_DATA: 2,1424|
[00:01:09.793,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,1424
[00:01:09.793,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:6)
[00:01:09.793,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:09.793,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:09.793,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:09.793,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:09.793,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:09.793,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:09.793,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:1424
[00:01:09.793,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,1424]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:09.804,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:09.804,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:09.804,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 1424 bytes
[00:01:09.804,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.855,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 579
[00:01:09.857,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:579
[00:01:09.857,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.909,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:1181
[00:01:09.909,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:09.960,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:09.960,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:09.960,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:09.960,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:09.960,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:09.960,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 1464)
487 z_impl_zsock_recvfrom: 1424 11
487 z_impl_zsock_recvfrom: -1 11
487 z_impl_zsock_recvfrom: -1 11
256 z_impl_zsock_connect: -1 11
z_impl_zsock_connect: -1 11
117 mqtt_client_tls_connect -1
[00:01:10.153,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:10.153,000] <dbg> modem_hl7800: offload_put: offload_put
[00:01:10.153,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4397
[00:01:10.153,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:10.153,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:10.153,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:10.153,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:10.153,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:10.153,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCLOSE=2]
[00:01:10.154,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:10.162,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:10.298,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPDEL=2]
[00:01:10.299,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:10.306,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:10.306,000] <dbg> modem_hl7800: set_busy: 0 called: 4407
[00:01:10.306,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4408
[00:01:10.306,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
80 client_connect -11
[00:01:10.306,000] <err> aws_iot: mqtt_connect, error: -11
[00:01:10.306,000] <err> aws_iot: AWS broker connect failed -11
[00:01:10.306,000] <dbg> cloud_module: cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTING
[00:01:15.306,000] <dbg> modem_hl7800: allow_sleep_work_callback: mdm_rat: 1 message pending 1, t3324 psmev: 0 allow shutdown: 0

I put some additional logs to trace what exactly issue:

#define VTABLE_CALL(fn, sock, ...)			     \
	({						     \
		const struct socket_op_vtable *vtable;	     \
		struct k_mutex *lock;			     \
		void *obj;				     \
		int retval;				     \
							     \
		obj = get_sock_vtable(sock, &vtable, &lock); \
		if (obj == NULL) {			     \
			errno = EBADF;			     \
			printk("%d %s: %d\n",__LINE__, __func__, errno); \
			return -1;			     \
		}					     \
							     \
		if (vtable->fn == NULL) {		     \
			errno = EOPNOTSUPP;		     \
			printk("%d %s: %d\n",__LINE__, __func__, errno); \
			return -1;			     \
		}					     \
							     \
		(void)k_mutex_lock(lock, K_FOREVER);         \
							     \
		retval = vtable->fn(obj, __VA_ARGS__);	     \
							     \
		printk("%d %s: %d %d\n",__LINE__, __func__, retval, errno); \
		k_mutex_unlock(lock);                        \
							     \
		retval;					     \
	})

123vodong · 2025-01-02T07:39:37Z

123vodong
Jan 2, 2025

I think it's related to CONFIG_NET_SOCKETS_CONNECT_TIMEOUT, default is 3000, you should increase it.
For example CONFIG_NET_SOCKETS_CONNECT_TIMEOUT=20000

7 replies

zafersn Jan 2, 2025
Author

Hi @rerickson1 Here is the log after enabling the mbedtls

[00:00:59.956,000] <dbg> modem_hl7800: offload_get: offload_get
[00:00:59.956,000] <dbg> modem_hl7800: offload_get: 4079 hl7800.c 1
[00:00:59.956,000] <dbg> modem_hl7800: set_busy: 0 called: 4096
[00:00:59.956,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4097
[00:00:59.956,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
47 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
55 mqtt_client_tls_connect
64 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
73 mqtt_client_tls_connect
84 mqtt_client_tls_connect
903 z_impl_zsock_setsockopt: 0 0
95 mqtt_client_tls_connect
112 mqtt_client_tls_connect 8 1
[00:00:59.956,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:00:59.956,000] <dbg> modem_hl7800: offload_bind: offload_bind
[00:00:59.956,000] <dbg> modem_hl7800: offload_connect: offload_connect
4163 offload_connect
4174 offload_connect
4195 offload_connect
4200 offload_connect
[00:00:59.957,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4204
[00:00:59.957,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:00:59.957,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:00:59.957,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:00:59.957,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:00:59.957,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
4205 offload_connect
[00:00:59.957,000] <dbg> modem_hl7800: offload_connect: Socket not created, configuring TCP socket
[00:00:59.957,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCFG=1,0,"3.251.41.141",8883,,,,0,,0]
[00:00:59.960,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
+KTCPCFG: 2
3977 hl.c 11 |+KTCPCFG: 2|
[00:00:59.979,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCPCFG: 2
[00:00:59.979,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCPCFG:  (len:1)
[00:00:59.979,000] <dbg> modem_hl7800_rx: on_cmd_sockcreate: +KTCPCFG: 2
[00:00:59.979,000] <dbg> modem_hl7800_rx: on_cmd_sockcreate: no sock, look up new socket by creation id
OK
[00:00:59.980,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
4216 offload_connect 0
[00:01:00.624,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCNX=2]
[00:01:00.625,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:00.649,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
+KTCP_IND: 2,1
3977 hl.c 14 |+KTCP_IND: 2,1|
[00:01:01.297,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_IND: 2,1
[00:01:01.297,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_IND:  (len:3)
[00:01:01.297,000] <dbg> modem_hl7800_rx: on_cmd_sock_ind: +KTCP_IND ID: 2
4229 offload_connect 0
[00:01:01.354,000] <dbg> modem_hl7800: set_busy: 0 called: 4230
[00:01:01.354,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4231
[00:01:01.354,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
4238 offload_connect 0
256 z_impl_zsock_connect: 0 0
z_impl_zsock_connect: 0 0
[00:01:01.370,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:1327: The SSL configuration is tls12 only.
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4606: => handshake
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_HELLO_REQUEST
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_CLIENT_HELLO
[00:01:01.372,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0919: => write client hello
[00:01:01.372,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0723: client hello, current time: ld
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0486: dumping 'client hello, random bytes' (32 bytes)
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0486: 0000:  ff ff ff ff f1 77 c1 c0 77 41 db 13 5d 92 ec 46  .....w..wA..]..F
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0486: 0010:  2c 92 23 72 2d 85 c0 7a 72 7c a5 d8 dc 5c 2d e7  ,.#r-..zr|...\-.
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0511: dumping 'session id' (0 bytes)
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: c09d, TLS-RSA-WITH-AES-256-CCM
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: 003d, TLS-RSA-WITH-AES-256-CBC-SHA256
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: c0a1, TLS-RSA-WITH-AES-256-CCM-8
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: 009c, TLS-RSA-WITH-AES-128-GCM-SHA256
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: c09c, TLS-RSA-WITH-AES-128-CCM
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: 003c, TLS-RSA-WITH-AES-128-CBC-SHA256
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0369: client hello, add ciphersuite: c0a0, TLS-RSA-WITH-AES-128-CCM-8
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0387: adding EMPTY_RENEGOTIATION_INFO_SCSV
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0396: client hello, got zu cipher suites
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0040: client hello, adding server name extension: a2hkw2qiy12x93-ats.iot.eu-west-1.amazonaws.com
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9370: adding signature_algorithms extension
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9390: got signature scheme [601] rsa_pkcs1_sha512
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9399: sent signature scheme [601] rsa_pkcs1_sha512
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9390: got signature scheme [401] rsa_pkcs1_sha256
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9399: sent signature scheme [401] rsa_pkcs1_sha256
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0688: client hello, total extension length: zu
[00:01:01.521,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: dumping 'client hello extensions' (65 bytes)
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: 0000:  00 41 00 00 00 33 00 31 00 00 2e 61 32 68 6b 77  .A...3.1...a2hkw
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: 0010:  32 71 69 79 31 32 78 39 33 2d 61 74 73 2e 69 6f  2qiy12x93-ats.io
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: 0020:  74 2e 65 75 2d 77 65 73 74 2d 31 2e 61 6d 61 7a  t.eu-west-1.amaz
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: 0030:  6f 6e 61 77 73 2e 63 6f 6d 00 0d 00 06 00 04 06  onaws.com.......
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:0690: 0040:  01                                               .
[00:01:01.522,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2783: => write handshake message
[00:01:01.522,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2943: => write record
[00:01:01.522,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3027: output record: msgtype = 22, version = [3:3], msglen = zu
[00:01:01.522,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: dumping 'output record sent to network' (131 bytes)
[00:01:01.522,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0000:  16 03 03 00 7e 01 00 00 7a 03 03 ff ff ff ff f1  ....~...z.......
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0010:  77 c1 c0 77 41 db 13 5d 92 ec 46 2c 92 23 72 2d  w..wA..]..F,.#r-
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0020:  85 c0 7a 72 7c a5 d8 dc 5c 2d e7 00 00 10 c0 9d  ..zr|...\-......
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0030:  00 3d c0 a1 00 9c c0 9c 00 3c c0 a0 00 ff 01 00  .=.......<......
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0040:  00 41 00 00 00 33 00 31 00 00 2e 61 32 68 6b 77  .A...3.1...a2hkw
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0050:  32 71 69 79 31 32 78 39 33 2d 61 74 73 2e 69 6f  2qiy12x93-ats.io
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0060:  74 2e 65 75 2d 77 65 73 74 2d 31 2e 61 6d 61 7a  t.eu-west-1.amaz
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0070:  6f 6e 61 77 73 2e 63 6f 6d 00 0d 00 06 00 04 06  onaws.com.......
[00:01:01.523,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0080:  01 04 01                                         ...
[00:01:01.523,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3080: <= write record
[00:01:01.523,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2904: <= write handshake message
[00:01:01.523,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_client.c:1012: <= write client hello
[00:01:01.523,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:01.524,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2367: message length: zu, out_left: zu
[00:01:01.524,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:01.524,000] <dbg> modem_hl7800: offload_send: offload_send
[00:01:01.524,000] <dbg> modem_hl7800: offload_sendto: offload_sendto
[00:01:01.524,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4300
[00:01:01.524,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:01.524,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:01.524,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:01.524,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:01.524,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:01.524,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPSND=2,131]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:01.535,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:01.535,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:02.270,000] <dbg> modem_hl7800: send_data: Sent 131 bytes
OK
[00:01:02.277,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:02.278,000] <dbg> modem_hl7800: set_busy: 0 called: 4306
[00:01:02.278,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4307
[00:01:02.278,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
345 z_impl_zsock_sendto: 131 0
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2374: ssl->f_send() returned 131 (-0xffffff7d)
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2401: <= flush output
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_SERVER_HELLO
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1195: => parse server hello
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4189: => read record
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: -1 11
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:02.278,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4617: <= handshake
+KTCP_DATA: 2,1424
3977 hl.c 18 |+KTCP_DATA: 2,1424|
[00:01:03.872,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,1424
[00:01:03.872,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:6)
[00:01:03.872,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:03.872,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:03.872,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:03.872,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:03.872,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:03.872,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:03.872,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:1424
[00:01:03.872,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,1424]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:03.883,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:03.883,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:03.883,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 1424 bytes
[00:01:03.883,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:03.933,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 578
[00:01:03.935,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:578
[00:01:03.935,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:03.986,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:1174
[00:01:03.986,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:04.037,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:04.037,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:04.037,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:04.037,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:04.037,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:04.037,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 1464)
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4606: => handshake
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_SERVER_HELLO
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1195: => parse server hello
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4189: => read record
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:04.037,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 5 11
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2340: <= fetch input
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: dumping 'input record header' (5 bytes)
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: 0000:  16 03 03 00 55                                   ....U
[00:01:04.038,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3857: input record: msgtype = 22, version = [0x303], msglen = zu
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 85 11
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 85 (-0xffffffab)
[00:01:04.038,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2340: <= fetch input
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: dumping 'input record from network' (90 bytes)
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0000:  16 03 03 00 55 02 00 00 51 03 03 e7 a1 2b db eb  ....U...Q....+..
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0010:  96 22 0e 8c 0c 48 fc 3b ab be 65 32 18 e3 05 3a  ."...H.;..e2...:
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0020:  32 d2 b5 44 4f 57 4e 47 52 44 01 20 89 5e d0 dd  2..DOWNGRD. .^..
[00:01:04.038,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0030:  69 a5 b0 8b ac bb cb 59 92 d9 14 c4 c6 a3 3d e0  i......Y......=.
[00:01:04.039,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0040:  a4 59 6e 57 bf d1 d1 a5 f1 47 11 7d 00 9c 00 00  .YnW.....G.}....
[00:01:04.039,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0050:  09 00 00 00 00 ff 01 00 01 00                    ..........
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3231: handshake message: msglen = zu, type = 85, hslen = zu
[00:01:04.039,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4261: <= read record
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1269: dumping 'server hello, version' (2 bytes)
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1269: 0000:  03 03                                            ..
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1290: server hello, current time: 3886099419
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1300: dumping 'server hello, random bytes' (32 bytes)
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1300: 0000:  e7 a1 2b db eb 96 22 0e 8c 0c 48 fc 3b ab be 65  ..+..."...H.;..e
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1300: 0010:  32 18 e3 05 3a 32 d2 b5 44 4f 57 4e 47 52 44 01  2...:2..DOWNGRD.
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1362: server hello, session id len.: zu
[00:01:04.039,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1363: dumping 'server hello, session id' (32 bytes)
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1363: 0000:  89 5e d0 dd 69 a5 b0 8b ac bb cb 59 92 d9 14 c4  .^..i......Y....
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1363: 0010:  c6 a3 3d e0 a4 59 6e 57 bf d1 d1 a5 f1 47 11 7d  ..=..YnW.....G.}
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1387: no session has been resumed
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1390: server hello, chosen ciphersuite: 009c
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1391: server hello, compress alg.: 0
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1426: server hello, chosen ciphersuite: TLS-RSA-WITH-AES-128-GCM-SHA256
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1447: server hello, total extension length: zu
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1592: unknown extension found: 0 (ignoring)
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1465: found renegotiation extension
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls12_client.c:1661: <= parse server hello
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_SERVER_CERTIFICATE
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7962: => parse certificate
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4189: => read record
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 5 11
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2340: <= fetch input
[00:01:04.040,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: dumping 'input record header' (5 bytes)
[00:01:04.040,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: 0000:  16 03 03 13 8c                                   .....
[00:01:04.040,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3857: input record: msgtype = 22, version = [0x303], msglen = zu
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:04.040,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 1329 11
[00:01:04.041,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:04.041,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 1329 (-0xfffffacf)
487 z_impl_zsock_recvfrom: -1 11
[00:01:04.041,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:04.041,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4617: <= handshake
+KTCP_DATA: 2,1424
3977 hl.c 18 |+KTCP_DATA: 2,1424|
[00:01:04.529,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,1424
[00:01:04.529,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:6)
[00:01:04.529,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:04.529,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:04.529,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:04.529,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:04.529,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:04.529,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:04.529,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:1424
[00:01:04.529,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,1424]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:04.540,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:04.540,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:04.540,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 1424 bytes
[00:01:04.540,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:04.591,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 580
[00:01:04.592,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:580
[00:01:04.592,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:04.644,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:1177
[00:01:04.644,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:04.694,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:04.694,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:04.694,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:04.694,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:04.694,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:04.694,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 1464)
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4606: => handshake
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_SERVER_CERTIFICATE
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7962: => parse certificate
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4189: => read record
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2340: <= fetch input
[00:01:05.171,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: dumping 'input record header' (5 bytes)
[00:01:05.171,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: 0000:  16 03 03 13 8c                                   .....
[00:01:05.171,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3857: input record: msgtype = 22, version = [0x303], msglen = zu
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 1424 11
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 1424 (-0xfffffa70)
487 z_impl_zsock_recvfrom: -1 11
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:05.171,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4617: <= handshake
+KTCP_DATA: 2,1424
3977 hl.c 18 |+KTCP_DATA: 2,1424|
[00:01:05.789,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,1424
[00:01:05.789,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:6)
[00:01:05.789,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:05.789,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:05.789,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:05.789,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:05.789,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:05.789,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:05.789,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:1424
[00:01:05.789,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,1424]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:05.800,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:05.800,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:05.800,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 1424 bytes
[00:01:05.800,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:05.850,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 578
[00:01:05.852,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:578
[00:01:05.852,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:05.903,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:1174
[00:01:05.903,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:05.954,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:05.954,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:05.954,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:05.954,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:05.954,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:05.954,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 1464)
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4606: => handshake
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2362: <= flush output
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4525: client state: MBEDTLS_SSL_SERVER_CERTIFICATE
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7962: => parse certificate
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4189: => read record
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
[00:01:05.954,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2340: <= fetch input
[00:01:05.955,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: dumping 'input record header' (5 bytes)
[00:01:05.955,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3855: 0000:  16 03 03 13 8c                                   .....
[00:01:05.955,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3857: input record: msgtype = 22, version = [0x303], msglen = zu
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2155: => fetch input
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2295: in_left: zu, nb_want: zu
487 z_impl_zsock_recvfrom: 1424 11
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2318: ssl->f_recv(_timeout)() returned 1424 (-0xfffffa70)
487 z_impl_zsock_recvfrom: -1 11
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2315: in_left: zu, nb_want: zu
[00:01:05.955,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4617: <= handshake
+KTCP_DATA: 2,827
3977 hl.c 17 |+KTCP_DATA: 2,827|
[00:01:06.514,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,827
[00:01:06.514,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:5)
[00:01:06.514,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:06.514,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:06.514,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:06.514,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:06.514,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:06.514,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:06.514,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:827
[00:01:06.514,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,827]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:06.525,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:06.525,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:06.525,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 827 bytes
[00:01:06.525,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:06.575,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 579
[00:01:06.577,000] <dbg> modem_hl7800_rx: sock_read: RX more data, bytes RXd:579
[00:01:06.577,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:06.628,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:42)
[00:01:06.628,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:06.628,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:06.628,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:06.628,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
+KTCP_DATA: 2,43
3977 hl.c 16 |+KTCP_DATA: 2,43|
[00:01:06.628,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,43
[00:01:06.628,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:4)
[00:01:06.628,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:06.628,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:06.628,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:06.628,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:06.628,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:06.628,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:06.628,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:43
[00:01:06.628,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,43]
[00:01:06.629,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 867)
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:06.639,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:06.639,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:06.639,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 43 bytes
[00:01:06.639,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:06.689,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 84
[00:01:06.689,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:41)
[00:01:06.689,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:06.689,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:06.689,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:06.689,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
+KTCP_DATA: 2,9
3977 hl.c 15 |+KTCP_DATA: 2,9|
[00:01:06.690,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: +KTCP_DATA: 2,9
[00:01:06.690,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE +KTCP_DATA:  (len:3)
[00:01:06.690,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 3582
[00:01:06.690,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:06.690,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:06.690,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:06.690,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:06.690,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:06.690,000] <dbg> modem_hl7800_rx: start_socket_rx: Start socket RX ID:2 size:9
[00:01:06.690,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPRCV=2,9]
[00:01:06.691,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 83)
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:06.701,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:06.701,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:06.701,000] <dbg> modem_hl7800_rx: sock_read: Socket 2 RX 9 bytes
[00:01:06.701,000] <dbg> modem_hl7800_rx: wait_for_modem_data: cur:0, exp:1
[00:01:06.751,000] <dbg> modem_hl7800_rx: sock_read: Processing RX, buf len: 31
[00:01:06.751,000] <dbg> modem_hl7800_rx: sock_read: Got all data, get EOF and OK (buf len:22)
[00:01:06.751,000] <dbg> modem_hl7800_rx: sock_read: Sock 2 RX done
[00:01:06.751,000] <dbg> modem_hl7800: set_busy: 0 called: 3386
[00:01:06.751,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 3387
[00:01:06.751,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
[00:01:06.751,000] <dbg> modem_hl7800_rx: sockreadrecv_cb_work: Sock 2 RX CB (size: 49)
[00:01:07.078,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0af0:  13 1c 53 74 61 72 66 69 65 6c 64 20 54 65 63 68  ..Starfield Tech
--- 196 messages dropped ---
[00:01:07.078,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0b20:  6c 64 20 53 65 72 76 69 63 65 73 20 52 6f 6f 74  ld Services Root
[00:01:07.078,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0b30:  20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74   Certificate Aut
[00:01:07.078,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0b40:  68 6f 72 69 74 79 20 2d 20 47 32 30 1e 17 0d 31  hority - G20...1
[00:01:07.089,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3964: 0ff0:  03 55 04 07 13 0a 53 63 6f 74 74 73 64 61 6c 65  .U....Scottsdale
--- 196 messages dropped ---
[00:01:07.089,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3231: handshake message: msglen = zu, type = 5004, hslen = zu
[00:01:07.091,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:4261: <= read record
[00:01:07.092,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: peer certificate #1:
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: cert. version     : 3
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: serial number     : 04:83:77:02:F6:2F:7A:39:61:31:41:F2:29:7A:8E:CF
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: issuer name       : C=US, O=Amazon, CN=Amazon RSA 2048 M01
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: subject name      : CN=*.iot.eu-west-1.amazonaws.com
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: issued  on        : 2024-08-21 00:00:00
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: expires on        : 2025-07-28 23:59:59
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: signed using      : RSA with SHA-256
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: RSA key size      : 2048 bits
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: basic constraints : CA=false
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: subject alt name  :
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834:     dNSName : iot.eu-west-1.amazonaws.com
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834:     dNSName : *.iot.eu-west-1.amazonaws.com
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: key usage         : Digital Signature, Key Encipherment
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: ext key usage     : TLS Web Server Authentication, TLS Web Client Authentication
[00:01:07.093,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834: certificate policies : ???
--- 196 messages dropped ---
[00:01:07.104,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:7834:  01 00 01
[00:01:07.104,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9807: Use configuration-specific verification callback
[00:01:07.177,000] <err> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9858: x509_verify_cert() returned -9984 (-0x2700)
[00:01:07.177,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:5168: => send alert message
[00:01:07.177,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:5169: send alert level=2 message=46
[00:01:07.177,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2943: => write record
[00:01:07.177,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3027: output record: msgtype = 21, version = [3:3], msglen = zu
[00:01:07.177,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: dumping 'output record sent to network' (7 bytes)
[00:01:07.177,000] <dbg> mbedtls_dbg: zephyr_mbedtls_debug: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3032: 0000:  15 03 03 00 02 02 2e                             .......
[00:01:07.177,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2353: => flush output
[00:01:07.177,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2367: message length: zu, out_left: zu
[00:01:07.177,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:07.177,000] <dbg> modem_hl7800: offload_send: offload_send
[00:01:07.177,000] <dbg> modem_hl7800: offload_sendto: offload_sendto
[00:01:07.177,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4300
[00:01:07.177,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:07.178,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:07.178,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:07.178,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:07.178,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:07.178,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPSND=2,7]
CONNECT
3977 hl.c 7 |CONNECT|
[00:01:07.189,000] <dbg> modem_hl7800_rx: hl7800_rx: 3979 hl7800_rx.c msg: CONNECT
[00:01:07.189,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE CONNECT (len:0)
[00:01:10.512,000] <dbg> modem_hl7800: send_data: Sent 7 bytes
OK
[00:01:10.520,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:10.520,000] <dbg> modem_hl7800: set_busy: 0 called: 4306
[00:01:10.520,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4307
[00:01:10.520,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
345 z_impl_zsock_sendto: 7 11
[00:01:10.520,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2374: ssl->f_send() returned 7 (-0xfffffff9)
[00:01:10.520,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:2401: <= flush output
[00:01:10.520,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:3080: <= write record
[00:01:10.520,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:5180: <= send alert message
[00:01:10.520,000] <inf> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:9958: ! Certificate verification flags 00000200
[00:01:10.521,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_tls.c:4617: <= handshake
256 z_impl_zsock_connect: -1 113
z_impl_zsock_connect: -1 113
117 mqtt_client_tls_connect -1
[00:01:10.522,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:6196: => write close notify
[00:01:10.522,000] <wrn> mbedtls_dbg: WEST_TOPDIR/modules/crypto/mbedtls/library/ssl_msg.c:6207: <= write close notify
[00:01:10.524,000] <dbg> modem_hl7800: offload_recv: offload_recv
[00:01:10.524,000] <dbg> modem_hl7800: offload_put: offload_put
[00:01:10.524,000] <dbg> modem_hl7800: wakeup_hl7800: CALLED FROM 4397
[00:01:10.524,000] <dbg> modem_hl7800: set_busy: 1 called: 519
[00:01:10.524,000] <dbg> modem_hl7800: allow_sleep: Keep awake 522
[00:01:10.524,000] <dbg> modem_hl7800: allow_sleep_with_timeout: Keep awake
[00:01:10.524,000] <dbg> modem_hl7800: wakeup_hl7800: desired_sleep_level 2 1 2 5
[00:01:10.524,000] <dbg> modem_hl7800: is_cmd_ready: 275 541 LOWPOWER VGPIO:1 GPIO6:1 UART_CTS:0 
[00:01:10.524,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPCLOSE=2]
[00:01:10.525,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:10.533,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:10.745,000] <dbg> modem_hl7800: send_at_cmd: OUT: [AT+KTCPDEL=2]
[00:01:10.746,000] <dbg> modem_hl7800: send_at_cmd: SEND ATCMD k_sem_take RET11 (SOCK_SEND_SEM): 0
OK
[00:01:10.752,000] <dbg> modem_hl7800_rx: hl7800_rx: HANDLE OK (len:0)
[00:01:10.752,000] <dbg> modem_hl7800: set_busy: 0 called: 4407
[00:01:10.752,000] <dbg> modem_hl7800: allow_sleep: Keep sleep 4408
[00:01:10.752,000] <dbg> modem_hl7800: allow_sleep_with_timeout: sleep scheduled
80 client_connect -113
[00:01:10.752,000] <err> aws_iot: mqtt_connect, error: -113
[00:01:10.752,000] <err> aws_iot: AWS broker connect failed -113
[00:01:10.752,000] <dbg> cloud_module: cloud_wrap_event_handler: CLOUD_WRAP_EVT_CONNECTING

rerickson1 Jan 2, 2025
Collaborator

There is an issue verifying your TLS certificate. Is TLS SNI and/or peer verification enabled? Are you using self signed certs?

zafersn Jan 2, 2025
Author

# TLS configuration
CONFIG_MBEDTLS=y
CONFIG_MBEDTLS_DTLS=y
CONFIG_MBEDTLS_BUILTIN=y
CONFIG_MBEDTLS_ENABLE_HEAP=y
CONFIG_MBEDTLS_HEAP_SIZE=65536
CONFIG_MBEDTLS_SSL_MAX_CONTENT_LEN=16384
CONFIG_MBEDTLS_PEM_CERTIFICATE_FORMAT=y
CONFIG_MBEDTLS_KEY_EXCHANGE_PSK_ENABLED=y
CONFIG_MBEDTLS_SERVER_NAME_INDICATION=y
CONFIG_MBEDTLS_AES_ROM_TABLES=y
CONFIG_MBEDTLS_TLS_VERSION_1_2=y
CONFIG_MBEDTLS_MEMORY_DEBUG=y
CONFIG_MBEDTLS_HAVE_TIME_DATE=y
CONFIG_MBEDTLS_SSL_ALPN=y
CONFIG_MBEDTLS_DEBUG=y
#cryptology
CONFIG_CRYPTO=y
CONFIG_MBEDTLS_CIPHER_CCM_ENABLED=y
CONFIG_MBEDTLS_CIPHER_GCM_ENABLED=y
CONFIG_CRYPTO_MBEDTLS_SHIM=y

# CONFIG_MBEDTLS_LOG_LEVEL=4
CONFIG_MBEDTLS_LOG_LEVEL_DBG=y

*
*
*
*
CONFIG_MQTT_LIB=y
CONFIG_MQTT_LIB_TLS=y
CONFIG_MQTT_KEEPALIVE=60
CONFIG_MQTT_LIB_TLS_USE_ALPN=y

These are the configs I am using.

Is TLS SNI and/or peer verification enabled?

@rerickson1 I am not an expert on the network side, so some of the information I provide may not be relevant. I apologize for that. From what I understand, you are asking about...

Yes peer verification is enabled.

static int client_broker_init(struct mqtt_client *const client)
{
	int err;

	mqtt_client_init(client);

	err = broker_init();
	if (err) {
		return err;
	}

	client->broker			= &broker;
	client->evt_cb			= mqtt_evt_handler;
	client->client_id.utf8		= (char *)client_id_buf;
	client->client_id.size		= strlen(client_id_buf);
	client->password		= NULL;
	client->user_name		= NULL;
	client->protocol_version	= MQTT_VERSION_3_1_1;
	client->rx_buf			= rx_buffer;
	client->rx_buf_size		= sizeof(rx_buffer);
	client->tx_buf			= tx_buffer;
	client->tx_buf_size		= sizeof(tx_buffer);
	client->transport.type		= MQTT_TRANSPORT_SECURE;

#if defined(CONFIG_AWS_IOT_LAST_WILL)
	static struct mqtt_topic last_will_topic = {
		.topic.utf8 = CONFIG_AWS_IOT_LAST_WILL_TOPIC,
		.topic.size = sizeof(CONFIG_AWS_IOT_LAST_WILL_TOPIC) - 1,
		.qos = MQTT_QOS_0_AT_MOST_ONCE
	};

	static struct mqtt_utf8 last_will_message = {
		.utf8 = CONFIG_AWS_IOT_LAST_WILL_MESSAGE,
		.size = sizeof(CONFIG_AWS_IOT_LAST_WILL_MESSAGE) - 1
	};

	client->will_topic = &last_will_topic;
	client->will_message = &last_will_message;
#endif

	static sec_tag_t sec_tag_list[] = { CONFIG_AWS_IOT_SEC_TAG };
	struct mqtt_sec_config *tls_cfg = &(client->transport).tls.config;

	tls_cfg->peer_verify		= TLS_PEER_VERIFY_REQUIRED;
	tls_cfg->cipher_count		= 0;
	tls_cfg->cipher_list		= NULL;
	tls_cfg->sec_tag_count		= ARRAY_SIZE(sec_tag_list);
	tls_cfg->sec_tag_list		= sec_tag_list;
	tls_cfg->hostname		= aws_host_name_buf;
	// tls_cfg->session_cache = TLS_SESSION_CACHE_DISABLED;

#if defined(CONFIG_AWS_IOT_PROVISION_CERTIFICATES)
	err = certificates_provision();
	if (err) {
		LOG_ERR("Could not provision certificates, error: %d", err);
		return err;
	}
#endif /* CONFIG_AWS_IOT_PROVISION_CERTIFICATES */

	return err;
}

Are you using self signed certs?

No, I downloaded and hardcoded the AWS certs (CA, private key, and certificate) into the application in this example. I am using the exact same application and compiling it with Zephyr 3.6.0. It works.

rerickson1 Jan 2, 2025
Collaborator

I bet the default ciphers enabled with 4.x changed. Compare your mbedtls kconfigs from 3.6 and 4.0 to see what are enabled.

rerickson1 Jan 9, 2025
Collaborator

@zafersn I believe this is directly related to #81672 (comment)

I am looking into what changed and how to fix.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

mqtt_connect, error: -11 #83489

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 1 comment 7 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

Select a reply

mqtt_connect, error: -11 #83489

zafersn Jan 2, 2025

Replies: 1 comment · 7 replies

123vodong Jan 2, 2025

zafersn Jan 2, 2025 Author

rerickson1 Jan 2, 2025 Collaborator

zafersn Jan 2, 2025 Author

rerickson1 Jan 2, 2025 Collaborator

rerickson1 Jan 9, 2025 Collaborator

zafersn
Jan 2, 2025

Replies: 1 comment 7 replies

123vodong
Jan 2, 2025

zafersn Jan 2, 2025
Author

rerickson1 Jan 2, 2025
Collaborator

zafersn Jan 2, 2025
Author

rerickson1 Jan 2, 2025
Collaborator

rerickson1 Jan 9, 2025
Collaborator