Modem data reconnection is not working with 5.0-rc1 IDF (IDFGH-8893)

[cpgoga]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

In case the IP is lost during normal operation, the modem should be able to reconnect to the internet and this is possible with the CMUX manual mode updates from espressif/esp-protocols#169 and the IDF 5.0 (commit 01d014c) but it is no longer possible with IDF 5.0-rc1 framework.

Preconditions:
IDF 5.0-rc1 + the changes from espressif/esp-protocols#169 integrated

Steps:

• trigger modem connection to internet
• simulate a lost IP event by detaching from network
• trigger modem re-connection to internet

Expected results:

• IP is obtained
• IP is lost
• IP is again obtained

Observed results:

• IP is obtained
• IP is lost
• IP is not obtained again (stuck in wait for IP state), connection times out

See also attached logs.
5.0_IDF_PASSED.txt
5.0-rc1_IDF_FAILED.txt

[chipweinberger]

v5.0 was just released btw! worth updating.

[franz-ms-muc]

related espressif/esp-protocols#188

[franz-ms-muc]

v5.0 was just released btw! worth updating.

same issue with 5.0 release !

[david-cermak]

@cpgoga Could you please try to apply this lwip patch to see if it helps?

diff --git a/src/netif/ppp/pppos.c b/src/netif/ppp/pppos.c
index 78a8d271..598e7051 100644
--- a/src/netif/ppp/pppos.c
+++ b/src/netif/ppp/pppos.c
@@ -226,7 +226,7 @@ pppos_write(ppp_pcb *ppp, void *ctx, struct pbuf *p)
   /* If the link has been idle, we'll send a fresh flag character to
    * flush any noise. */
   err = ERR_OK;
-  if ((sys_now() - pppos->last_xmit) >= PPP_MAXIDLEFLAG) {
+  if (1) {
     err = pppos_output_append(pppos, err,  nb, PPP_FLAG, 0, NULL);
   }
 
@@ -276,7 +276,7 @@ pppos_netif_output(ppp_pcb *ppp, void *ctx, struct pbuf *pb, u16_t protocol)
   /* If the link has been idle, we'll send a fresh flag character to
    * flush any noise. */
   err = ERR_OK;
-  if ((sys_now() - pppos->last_xmit) >= PPP_MAXIDLEFLAG) {
+  if (1) {
     err = pppos_output_append(pppos, err,  nb, PPP_FLAG, 0, NULL);
   }

[MartinPatarinski]

Just tested with the fixes above on my side. Also enabled PPPOS logging in menuconfig. I see two strange things that may help to understand the problem:

1. When connected, the enterring of command mode seems not to work
   I (12:50:44.183) ESPmodem_Cmux: CMUX-Command mode set
   sent [LCP TermReq id=0x3 "User request"]
   pppos_write[1]: output failed len=20
2. When reconnecting, IP is not obtained
   Could not determine remote IP address: defaulting to 10.64.64.64

---

Log file:
Second_Enter_Data_Fails.txt

[david-cermak]

Thanks for the quick test and sharing debug logs from PPP service!

Ad 1) There was a minor bug in esp-modem that might have caused the issue. Fixed in espressif/esp-protocols@9a7bd90.

Ad 2) The log looks differently now, we are able to communicate on PPPoS protocol, just couldn't obtain an IP. Would it be possible that in this case the device couldn't reconnect due to network issues? The log above (before patching lwip) shows that we were not able to connect at all (entering PPPoS in lwip failed)

[franz-ms-muc]

Ad 1) There was a minor bug in esp-modem that might have caused the issue. Fixed in espressif/esp-protocols@9a7bd90.

espressif/esp-protocols#188 for my Tests.

even with the fix, it still works in ESP-IDF 4.4.2 and fails in ESP-IDF 5.0

did logs for all with 

CONFIG_LOG_DEFAULT_LEVEL_VERBOSE=y

CONFIG_LWIP_PPP_DEBUG_ON=y

please check !

[david-cermak]

Found the problem, it wasn't in lwip, but in a way we interpret getting IP address notifications. In v4.4 we used custom callbacks in PPP modules, but from v5.0 we switched to standard IP-changed notifications. The problem is if we lose connection and reconnect with the same IP.
This should work around the problem, but would need to think the actual fix over.

diff --git a/components/esp_netif/lwip/esp_netif_lwip.c b/components/esp_netif/lwip/esp_netif_lwip.c
index f41249ba45..d303639e8e 100644
--- a/components/esp_netif/lwip/esp_netif_lwip.c
+++ b/components/esp_netif/lwip/esp_netif_lwip.c
@@ -1217,6 +1217,9 @@ static void esp_netif_internal_dhcpc_cb(struct netif *netif)
     } else {
         if (!ip4_addr_cmp(&ip_info->ip, IP4_ADDR_ANY4)) {
             esp_netif_start_ip_lost_timer(esp_netif);
+            ip4_addr_set(&ip_info->ip, ip_2_ip4(&netif->ip_addr));
+            ip4_addr_set(&ip_info->netmask, ip_2_ip4(&netif->netmask));
+            ip4_addr_set(&ip_info->gw, ip_2_ip4(&netif->gw));
         }
     }
 }

[franz-ms-muc]

Hi, 

tested this in ESP-IDF 5.0 Release, and this is working fine. 

pls integrate this in the next ESP-IDF.

thanks, 

Franz.

[MartinPatarinski]

The last provided workaround also works on our side. The change in pppos.c was reverted to the original code.
Thank you for the great support!
We await the integration in the ESP-IDF.