SOLVED: Lost TLS connection causes apparent LWIP memory leak
Posted: Mon Jul 31, 2023 4:17 am
Bear with me, I've been trying to debug what looked like a memory leak in LWIP for the last week and it has been a journey.
We're using TLS to connected to an AWS MQTT broker for an IoT device. We've been testing on a cellular Wi-Fi hotspot which sometimes has poor cellular signal, and this has revealed a problem with LWIP consuming heap memory and not releasing it.
Here's what happens:
* Device establishes Wi-Fi connection to cellular Wi-Fi hotspot.
* Device establishes TLS connection to MQTT broker. All works OK.
* Cellular signal fluctuates, we lose the network connection, and MQTT ping is missed (but Wi-Fi is still up).
* We disconnect the TLS connection and re-connect.
* MQTT works again.
This works, but we lose ~1900 bytes of free heap each time the TLS connection is lost and re-established. We don't have a lot of spare heap, so after ~ 5 - 10 reconnections, we don't have enough free heap to start another TLS connection, and are forced to reboot.
Here is the code used to create/open and close the TLS connection. From the header, it looks like this is all we should need to do (i.e. no other cleanup required):
Note that internally, ESP-TLS uses the "sockets" interface to open and close the TCP connection, i.e. "socket()", "connect()", "close()".
Heap tracing and a lot of code analysis shows that we are accumulating the MQTT ping messages sent after the data connection is lost. These are stored as "struct tcp_seg" structures in LWIP (see esp-idf\components\lwip\lwip\src\core\tcp.c, etc). They are stored in the "unacked" segment list, under the Protocol Control Block struct (struct tcp_pcb) for the connection. The PCB is referenced by the global list of connection PCBs stored in "tcp_active_pcbs", and also via the "sockets" list while it is open.
IN the case where the data connection is lost and the MQTT ping times out, we close the connection with esp_tls_conn_destroy as above. I thought these un-acked segments were never freed after that, but in fact they are. When I re-connected and left the new connection running for ~20 to 25 minutes, the old PCB and segments were eventually freed and deleted from the "tcp_active_pcbs" by the "TCP slow timer" function ("tcp_slowtmr"), and the "lost" heap was restored. However, this seems much too long to clean up a dead connection (which has already been closed via socket -> close()!) and in our case, frequently leads to running out of heap due to reconnections on dodgy cellular connections.
I've instrumented the LWIP code to trace the state for the dead connection. When "close()" is called, it is placed in "FIN_WAIT_1" state, and remains in the "tcp_active_pcbs" list. Maybe waiting for FIN from the other end, which it never receives?
In this state, the "tcp_slowtmr" runs every 500 mS and re-sends the un-acked segments periodically, using an exponential retry interval, and (by default) 12 retries. After 12 retries, the PCB is finally cleaned up.
However, the "retry" timeout (pcb->rto) starts at typically 2, 3, or 4 "ticks" (1 tick = 500 mS slow timer) and DOUBLES every retry up to a certain max:
The end result is that the dead connection is not cleaned up for at least 15 minutes, and potentially over 30 minutes.
Is this logic correct? It seems like a very long time for LWIP to retry sending segments on a dead connection. We really need it to give up and clean up the old connection after a couple of minutes MAX, so that we don't run out of free heap in the case where the connection is unstable! 15 minute gives us plenty of time to disconnect and reconnect to the TLS server a few times and run out of heap.
Other Info:
We are using ESP-IDF 4.4.4
The LWIP config provides these options which look relevant:
LWIP_TCP_MSL - Maximum segment lifetime (MSL) - Default 60000 mS
LWIP_TCP_FIN_WAIT_TIMEOUT - Maximum FIN segment lifetime - Default 20000 mS
However:
* LWIP_TCP_MSL is only used for connection state "LAST_ACK" or PCBs in the "TIME-WAIT" list.
* LWIP_TCP_FIN_WAIT_TIMEOUT is only used when the connection state is "FIN_WAIT_2", which we never reach with "dead" connections.
We're using TLS to connected to an AWS MQTT broker for an IoT device. We've been testing on a cellular Wi-Fi hotspot which sometimes has poor cellular signal, and this has revealed a problem with LWIP consuming heap memory and not releasing it.
Here's what happens:
* Device establishes Wi-Fi connection to cellular Wi-Fi hotspot.
* Device establishes TLS connection to MQTT broker. All works OK.
* Cellular signal fluctuates, we lose the network connection, and MQTT ping is missed (but Wi-Fi is still up).
* We disconnect the TLS connection and re-connect.
* MQTT works again.
This works, but we lose ~1900 bytes of free heap each time the TLS connection is lost and re-established. We don't have a lot of spare heap, so after ~ 5 - 10 reconnections, we don't have enough free heap to start another TLS connection, and are forced to reboot.
Here is the code used to create/open and close the TLS connection. From the header, it looks like this is all we should need to do (i.e. no other cleanup required):
Code: Select all
// Create / Connect:
esp_tls_t* pxTls = esp_tls_init();
esp_tls_conn_new_sync(...);
// Disconnect / Clean up:
esp_tls_conn_destroy(pxTls);
Heap tracing and a lot of code analysis shows that we are accumulating the MQTT ping messages sent after the data connection is lost. These are stored as "struct tcp_seg" structures in LWIP (see esp-idf\components\lwip\lwip\src\core\tcp.c, etc). They are stored in the "unacked" segment list, under the Protocol Control Block struct (struct tcp_pcb) for the connection. The PCB is referenced by the global list of connection PCBs stored in "tcp_active_pcbs", and also via the "sockets" list while it is open.
IN the case where the data connection is lost and the MQTT ping times out, we close the connection with esp_tls_conn_destroy as above. I thought these un-acked segments were never freed after that, but in fact they are. When I re-connected and left the new connection running for ~20 to 25 minutes, the old PCB and segments were eventually freed and deleted from the "tcp_active_pcbs" by the "TCP slow timer" function ("tcp_slowtmr"), and the "lost" heap was restored. However, this seems much too long to clean up a dead connection (which has already been closed via socket -> close()!) and in our case, frequently leads to running out of heap due to reconnections on dodgy cellular connections.
I've instrumented the LWIP code to trace the state for the dead connection. When "close()" is called, it is placed in "FIN_WAIT_1" state, and remains in the "tcp_active_pcbs" list. Maybe waiting for FIN from the other end, which it never receives?
In this state, the "tcp_slowtmr" runs every 500 mS and re-sends the un-acked segments periodically, using an exponential retry interval, and (by default) 12 retries. After 12 retries, the PCB is finally cleaned up.
However, the "retry" timeout (pcb->rto) starts at typically 2, 3, or 4 "ticks" (1 tick = 500 mS slow timer) and DOUBLES every retry up to a certain max:
Code: Select all
static const u8_t tcp_backoff[13] = { 1, 2, 3, 4, 5, 6, 7, 7, 7, 7, 7, 7, 7};
...
int calc_rto = ((pcb->sa >> 3) + pcb->sv) << tcp_backoff[backoff_idx];
Is this logic correct? It seems like a very long time for LWIP to retry sending segments on a dead connection. We really need it to give up and clean up the old connection after a couple of minutes MAX, so that we don't run out of free heap in the case where the connection is unstable! 15 minute gives us plenty of time to disconnect and reconnect to the TLS server a few times and run out of heap.
Other Info:
We are using ESP-IDF 4.4.4
The LWIP config provides these options which look relevant:
LWIP_TCP_MSL - Maximum segment lifetime (MSL) - Default 60000 mS
LWIP_TCP_FIN_WAIT_TIMEOUT - Maximum FIN segment lifetime - Default 20000 mS
However:
* LWIP_TCP_MSL is only used for connection state "LAST_ACK" or PCBs in the "TIME-WAIT" list.
* LWIP_TCP_FIN_WAIT_TIMEOUT is only used when the connection state is "FIN_WAIT_2", which we never reach with "dead" connections.