Problems getting DNS IP Addresses with esp_modem 1.4.0 and esp-idf 5.5 (IDFGH-16617)

[FabITA1]

Answers checklist.

• I have read the documentation for esp-protocols components and the issue is not addressed there.
• I have updated my esp-protocols 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

Hi,
I have an application with esp32s3 running esp-idf 5.5, esp_modem 1.4.0, pppos client in cmux mode and a Quectel modem.
I have problems getting DNS server IP Addr with some operators sim cards (Vodafone for example, but some others sim works fine).
The DNS servers have 0.0.0.0 address.
An other older application with esp_modem 1.0.0 and idf 4.4.3 runs fine with the same sim card and modem.
Here the log of the IP negotiation phase:

D (22598) esp_netif_lwip: esp_netif_start_api 0x3fcd1ee4
D (22598) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3fcd2200
D (22598) esp-netif_lwip-ppp: ppp: Phase Start
D (22598) esp-netif_lwip-ppp: ppp: Phase Establish
D (22598) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (22598) Gest4G: Waiting for IP address
D (22608) CMUX: Payload frame: dlci:01 type:ef payload:51 available:61
D (22608) CMUX: Payload frame: dlci:01 type:ef payload:48 available:4
D (22608) CMUX: Payload frame: dlci:01 type:ef payload:44 available:46
D (22618) CMUX: Payload frame: dlci:01 type:ef payload:46 available:48
D (22618) esp-netif_lwip-ppp: ppp: Phase Authenticate
D (22618) esp-netif_lwip-ppp: ppp: Phase Network
D (22878) CMUX: Payload frame: dlci:01 type:ef payload:10 available:46
D (22878) CMUX: Payload frame: dlci:01 type:ef payload:28 available:30
D (22888) CMUX: Payload frame: dlci:01 type:ef payload:10 available:34
D (22888) CMUX: Payload frame: dlci:01 type:ef payload:16 available:18
D (22898) CMUX: Payload frame: dlci:01 type:ef payload:16 available:18
D (22898) esp_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcd0060
D (22898) esp_netif_lwip: check: local, if=0x3fcd1ee4 fn=0x420656a0
--- 0x420656a0: esp_netif_update_default_netif_lwip at /home/fabios/esp/v5.5/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:313
D (22898) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcd1ee4
D (22898) esp_netif_lwip: if0x3fcd1ee4 ip changed=1
D (22898) event: running post IP_EVENT:6 with handler 0x4201c294 and context 0x3fcd1ec4 on loop 0x3fcbb628
--- 0x4201c294: on_ip_event at /home/....._4G.c:180
D (22898) Gest4G: IP event! 6
I (22898) Gest4G: Modem Connect to PPP Server
I (22898) Gest4G: ~~~~~~~~~~~~~~
I (22898) Gest4G: IP : 10.248.22.225
I (22898) Gest4G: Netmask : 255.255.255.255
I (22898) Gest4G: Gateway : 10.64.64.64
D (22898) esp_netif_lwip: check: remote, if=0x3fcd1ee4 fn=0x420648b4
--- 0x420648b4: esp_netif_get_dns_info_api at /home/fabios/esp/v5.5/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:2117
I (22898) esp-netif_lwip-ppp: ppp: Connected
D (22898) esp-netif_lwip-ppp: ppp: Phase Running
D (22908) esp_netif_lwip: esp_netif_get_dns_info: esp_netif=0x3fcd1ee4 type=0
D (22918) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (22918) Gest4G: Name Server1: 0.0.0.0
D (22918) esp_netif_lwip: check: remote, if=0x3fcd1ee4 fn=0x420648b4
--- 0x420648b4: esp_netif_get_dns_info_api at /home/fabios/esp/v5.5/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:2117
D (22918) esp_netif_lwip: esp_netif_get_dns_info: esp_netif=0x3fcd1ee4 type=1
D (22918) esp_netif_lwip: call api in lwip: ret=0x0, give sem
I (22918) Gest4G: Name Server2: 0.0.0.0
I (22918) Gest4G: ~~~~~~~~~~~~~~
I (22918) Gest4G: GOT ip event!!!

Attached a log in verbose mode.

Log Verbose.txt

Can someboby give me some help?

[FabITA1]

I tried to set the DNS manually to 8.8.8.8/1.1.1.1, but the but the internet connection is not established.
Maybe it's not just a DNS problem...
Here some logs:

I (23467) Gest4G: Modem Connect to PPP Server
I (23467) Gest4G: ~~~~~~~~~~~~~~
I (23467) Gest4G: IP : 10.121.17.34
I (23467) Gest4G: Netmask : 255.255.255.255
I (23467) Gest4G: Gateway : 10.64.64.64
I (23467) esp-netif_lwip-ppp: ppp: Connected
pbuf_free(0x3fcd5920)
pbuf_free: deallocating 0x3fcd5920
pbuf_free(0x3fcd58e8)
pbuf_free: deallocating 0x3fcd58e8
W (23477) Gest4G: DNS info not received
I (23477) Gest4G: DNS fallback: 8.8.8.8 / 1.1.1.1
I (23477) Gest4G: Name Server1: 8.8.8.8
I (23477) Gest4G: Name Server2: 1.1.1.1
I (23477) Gest4G: ~~~~~~~~~~~~~~
I (23477) Gest4G: GOT ip event!!!
netif: setting default interface pp
I (23477) Gest4G: PPP state changed event 0
I (23497) GestComm: Initializing SNTP
sntp_init: SNTP initialised
I (23497) GestComm: Waiting for system time to be set... (0/8)
etharp_timer
dhcp_coarse_tmr()
etharp_timer
dhcp_coarse_tmr()
dns_enqueue: "ntp1.inrim.it": use DNS entry 0
udp_bind(ipaddr = 0.0.0.0, port = 64941)
udp_bind: bound to 0.0.0.0, port 64941)
dns_enqueue: "ntp1.inrim.it": use DNS pcb 0
dns_send: dns_servers[0] "ntp1.inrim.it": request
pbuf_alloc(length=31)
pbuf_alloc(length=31) == 0x3fcd5a6c
sending DNS request ID 45556 for name "ntp1.inrim.it" to server 0
udp_send
pbuf_add_header: old 0x3fcd5ac8 new 0x3fcd5ac0 (8)
udp_send: added header in given pbuf 0x3fcd5a6c
udp_send: sending datagram of length 39
udp_send: UDP packet length 39
udp_send: UDP checksum 0xeac4
udp_send: ip_output_if (,,,,0x11,)
pbuf_add_header: old 0x3fcd5ac0 new 0x3fcd5aac (20)
ip4_output_if: pp3
IP header:
+-------------------------------+
| 4 | 5 | 0x00 | 59 | (v, hl, tos, len)
+-------------------------------+
| 0 |000| 0 | (id, flags, offset)
+-------------------------------+
| 64 | 17 | 0x4f08 | (ttl, proto, chksum)
+-------------------------------+
| 10 | 121 | 17 | 34 | (src)
+-------------------------------+
| 8 | 8 | 8 | 8 | (dest)
+-------------------------------+
ip4_output_if: call netif->output()
pbuf_alloc(length=1516)
pbuf_alloc(length=1516) == 0x3fcd5aec
pbuf_free(0x3fcd5aec)
pbuf_free: deallocating 0x3fcd5aec
pbuf_free(0x3fcd5a6c)
pbuf_free: deallocating 0x3fcd5a6c
sntp_request: Waiting for server address to be resolved.
I (25497) GestComm: Waiting for system time to be set... (1/8)
etharp_timer
dhcp_coarse_tmr()
dns_tmr: dns_check_entries
dns_send: dns_servers[0] "ntp1.inrim.it": request
pbuf_alloc(length=31)
pbuf_alloc(length=31) == 0x3fcd5a6c
sending DNS request ID 45556 for name "ntp1.inrim.it" to server 0
udp_send
pbuf_add_header: old 0x3fcd5ac8 new 0x3fcd5ac0 (8)
udp_send: added header in given pbuf 0x3fcd5a6c
udp_send: sending datagram of length 39
udp_send: UDP packet length 39
udp_send: UDP checksum 0xeac4
udp_send: ip_output_if (,,,,0x11,)
pbuf_add_header: old 0x3fcd5ac0 new 0x3fcd5aac (20)
ip4_output_if: pp3
IP header:
+-------------------------------+
| 4 | 5 | 0x00 | 59 | (v, hl, tos, len)
+-------------------------------+
| 1 |000| 0 | (id, flags, offset)
+-------------------------------+
| 64 | 17 | 0x4f07 | (ttl, proto, chksum)
+-------------------------------+
| 10 | 121 | 17 | 34 | (src)
+-------------------------------+
| 8 | 8 | 8 | 8 | (dest)
+-------------------------------+
ip4_output_if: call netif->output()
pbuf_alloc(length=1516)
pbuf_alloc(length=1516) == 0x3fcd5aec
pbuf_free(0x3fcd5aec)
pbuf_free: deallocating 0x3fcd5aec
pbuf_free(0x3fcd5a6c)
pbuf_free: deallocating 0x3fcd5a6c
etharp_timer
dhcp_coarse_tmr()
dns_tmr: dns_check_entries
dns_send: dns_servers[0] "ntp1.inrim.it": request
pbuf_alloc(length=31)
pbuf_alloc(length=31) == 0x3fcd5a6c
sending DNS request ID 45556 for name "ntp1.inrim.it" to server 0
udp_send
pbuf_add_header: old 0x3fcd5ac8 new 0x3fcd5ac0 (8)
udp_send: added header in given pbuf 0x3fcd5a6c
udp_send: sending datagram of length 39
udp_send: UDP packet length 39
udp_send: UDP checksum 0xeac4
udp_send: ip_output_if (,,,,0x11,)
pbuf_add_header: old 0x3fcd5ac0 new 0x3fcd5aac (20)
ip4_output_if: pp3
IP header:
+-------------------------------+
| 4 | 5 | 0x00 | 59 | (v, hl, tos, len)
+-------------------------------+
| 2 |000| 0 | (id, flags, offset)
+-------------------------------+
| 64 | 17 | 0x4f06 | (ttl, proto, chksum)
+-------------------------------+
| 10 | 121 | 17 | 34 | (src)
+-------------------------------+
| 8 | 8 | 8 | 8 | (dest)
+-------------------------------+
ip4_output_if: call netif->output()
pbuf_alloc(length=1516)
pbuf_alloc(length=1516) == 0x3fcd5aec
pbuf_free(0x3fcd5aec)
pbuf_free: deallocating 0x3fcd5aec
pbuf_free(0x3fcd5a6c)
pbuf_free: deallocating 0x3fcd5a6c

[david-cermak]

Hi @FabITA1

Could you please enable PPP debug logs (LWIP_PPP_DEBUG_ON) and share the output?

(Top) → Component config → LWIP → Enable PPP support
[*] Enable PPP debug log output

Also, are you using other netifs at the same time? WiFi station/AP or Ethernet or something else? I see the netif's called pp3 so you probably are?

[FabITA1]

Hi @david-cermak
thanks for your reply.
Attached the log.

I also noted that:

• also if I forced the original DNS Vodafone Ip Address (instead of 8.8.8.8 ...) doesn't works
• if I try to connect direct Ip Address (not Url), doesn't works
• not only sntp (udp) doesn't work, but also mqtt (tcp)

I found another SIM (different operator) that doesn't work and this one also doesn't get the DNS from the server
With anoter sim, that automatic gives DNS from server, all work fine.

Log.txt

[FabITA1]

Hi @david-cermak ,
were you able to look at the logs? I'm stuck on this problem.

[david-cermak]

Interesting, that the server requests authentication, but the client rejects it:

rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0x391b5a39> <pcomp> <accomp>]
No auth is possible
sent [LCP ConfRej id=0x1 <auth pap>]
``

Do you use some login/password to connect to your modem? Could you please also post your sdkconfig?

[FabITA1]

No, I don't use login/pwd.
Here the sdkconfig.

sdkconfig.txt

[david-cermak]

No, I don't use login/pwd.

But from your sdkconfig:

CONFIG_EXAMPLE_MODEM_PPP_AUTH_USERNAME="espressif"
CONFIG_EXAMPLE_MODEM_PPP_AUTH_PASSWORD="esp32"

Maybe that's the reason it worked on v4.4, probably your operator just needs PPP/PAP to be enabled in the protocol?

Could you try to run this just after creating PPP netif?

esp_err_t ret = esp_netif_ppp_set_auth(s_netif, 
                                       NETIF_PPP_AUTHTYPE_PAP, 
                                       "espressif", 
                                       "esp32");
if (ret != ESP_OK) {
    ESP_LOGE(TAG, "Failed to set PPP authentication: %s", esp_err_to_name(ret));
}

[FabITA1]

But from your sdkconfig:

I did not set it voluntarily....
...actually in the old project sdkconfig there is
CONFIG_EXAMPLE_MODEM_PPP_AUTH_NONE=y

but I don't use this setting explicitly in my code. Is it used by netif?

Could you try to run this just after creating PPP netif?

You mean in the new 5.5 project?

[FabITA1]

Hi @david-cermak, I put the lines of code after creating the netif and before starting modem:
`
. . . . . .

Log.txt

		    G4G_Info.Netif = esp_netif_new(&netif_ppp_config);
		    assert(G4G_Info.Netif);

			ESP_LOGI(G4G_TAG, "------------------");
			esp_err_t ret = esp_netif_ppp_set_auth(G4G_Info.Netif, 
												NETIF_PPP_AUTHTYPE_PAP, 
												"espressif", 
												"esp32");
			if (ret != ESP_OK) {
				ESP_LOGE(G4G_TAG, "Failed to set PPP authentication: %s", esp_err_to_name(ret));
			}


		    /* Configure the DTE */
			esp_modem_dte_config_t dte_config = ESP_MODEM_DTE_DEFAULT_CONFIG();

. . . . . .
`

[FabITA1]

Hi @david-cermak,
I think I found the problem. Seems an APN problem.
In my application I need to get the IMSI of the sim inserted in the module for selecting the APN.
So first I init the DCE whith null APN:

    apn[0] = 0x00;
    esp_modem_dce_config_t dce_config = ESP_MODEM_DCE_DEFAULT_CONFIG((const char *)apn);
    ...
    dce = esp_modem_new_dev(ESP_MODEM_DCE_BG96, &dte_config, &dce_config, G4G_Info.Netif);

Then, when I get the IMSI from the sim, I set the right APN with:

    pdp_context.apn = (const char *)apn;
    pdp_context.context_id    = 1;
    pdp_context.protocol_type = "IP";
    err = esp_modem_set_pdp_context(dce, &pdp_context);

thinking this would update the setting I had previously made.

But, looking the logs, I see that with esp_modem_set_pdp_context()
D (15462) command_lib: generic_command command AT+CGDCONT=1,"IP","mobile.vodafone.it"
then when I start CMUX mode with esp_modem_set_mode(dce, ESP_MODEM_MODE_CMUX):

D (16712) command_lib: generic_command command AT+CGDCONT=1,"IP",""

V (16712) Send: 0x3fcbc104   f9 05 ef 2b                                       |...+|
V (16722) Send: 0x3fcc5edc   41 54 2b 43 47 44 43 4f  4e 54 3d 31 2c 22 49 50  |AT+CGDCONT=1,"IP|
V (16722) Send: 0x3fcc5eec   22 2c 22 22 0d                                    |","".|
V (16722) Send: 0x3fcbc108   83 f9                                             |..|

whith the null APN previously set. I think the problem is this.

What would be the correct procedure to do what I need?
Thanks