Closed Arthedian closed 3 years ago
suda-morris
commented
4 years ago There might be some regression in the uart driver, since 4.1 has introduced a HAL layer for drivers.
A regular way to locate the issue is using git bisect, could you tell the commit id that works for you?
Arthedian
commented
4 years ago Sadly I have no way how to find it, but probably I have some older version. I have tried example from v3.3.1, and it has the same problem. In my example, esp_modem doesnt write any DEBUG info about PPP phases. I have SIM800L connected to GPIO1 and GPIO3, and outwards logging through UART on GPIO32 and GPIO35.
Arthedian
commented
4 years ago I created a repo with working example (for me). https://github.com/Arthedian/esp32_gsm
EDIT:with the repo above, I have only problem If I deinit PPP, and want to init it again, than it will give loadprohibited error. But this is another problem, and thats why I wanted to use newer version.
D (106030) sim800: enter ppp mode ok
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x400ec216 PS : 0x00060f30 A0 : 0x800d6a25 A1 : 0x3ffcd270
A2 : 0x00000000 A3 : 0x3ffbd46c A4 : 0x0000002b A5 : 0x3ffcf784
A6 : 0x3ffb4934 A7 : 0x0000002b A8 : 0x800ec213 A9 : 0x3ffcd250
A10 : 0x00000000 A11 : 0x3ffbd46c A12 : 0x400ec434 A13 : 0x0000002b
A14 : 0x0000002b A15 : 0x0000002b SAR : 0x00000018 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000028 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000
ELF file SHA256: 413f1209914d7fb5a1dd1bdb6780d631cc5c9b8b535683fd653db7b7867942e4
Backtrace: 0x400ec213:0x3ffcd270 0x400d6a22:0x3ffcd290 0x400d6b7b:0x3ffcd2c0 0x400888b9:0x3ffcd2f0EDIT2: This output has backtrace from monitor:
D (107455) sim800: enter ppp mode ok
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC : 0x400efa8e PS : 0x00060e30 A0 : 0x800d6855 A1 : 0x3ffbfc20
0x400efa8e: pppos_input_tcpip at /home/arthedian/esp/esp-idf/components/lwip/lwip/src/netif/ppp/pppos.c:440
A2 : 0x00000000 A3 : 0x3ffd0c5c A4 : 0x0000002b A5 : 0x3ffdf674
A6 : 0x3ffb5bc0 A7 : 0x0000002b A8 : 0x800efa8b A9 : 0x3ffbfc00
A10 : 0x00000000 A11 : 0x3ffd0c5c A12 : 0x400efcac A13 : 0x0000002b
0x400efcac: pppos_input_sys at /home/arthedian/esp/esp-idf/components/lwip/lwip/src/netif/ppp/pppos.c:448
A14 : 0x0000002b A15 : 0x0000002b SAR : 0x00000018 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000028 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000
ELF file SHA256: d633b17e84f95b1a314dca37b46ec5f19cdc7e7d1940d83c8fd06c7272a42cc8
Backtrace: 0x400efa8b:0x3ffbfc20 0x400d6852:0x3ffbfc40 0x400d69ab:0x3ffbfc70 0x400885a5:0x3ffbfca0
0x400efa8b: pppos_input_tcpip at /home/arthedian/esp/esp-idf/components/lwip/lwip/src/netif/ppp/pppos.c:440
0x400d6852: esp_handle_uart_data at /home/arthedian/prace/BeiT/test/gsm_ota_test/build/../components/gsm/lib/esp_modem.c:151
0x400d69ab: uart_event_task_entry at /home/arthedian/prace/BeiT/test/gsm_ota_test/build/../components/gsm/lib/esp_modem.c:168
0x400885a5: vPortTaskWrapper at /home/arthedian/esp/esp-idf/components/freertos/port.c:143
amitcv
commented
4 years ago I have the exact same problem with same backtrace as above EDIT2. I am using bg96 module with esp-idf version v4.0 @Arthedian did you have any new ideas?
edwin-oetelaar
commented
4 years ago Same issues here. Latest idf. Verbose logging shows valid PPP connection. It seems callbacks are not fired. Will investigate further.
D (11810) event: running post ESP_MODEM_EVENT:0 with handler 0x400db5f8 and context 0x3ffc6fd8 on loop 0x3ffc4c8c
0x400db5f8: modem_event_handler at /home/oetelaar/esp/intercom_minimal/main/app_ppp.c:127
I (11813) pppos_example: Modem PPP Started
D (11817) event: running post ESP_MODEM_EVENT:0 with handler 0x400e16b0 and context 0x3ffc8a00 on loop 0x3ffc4c8c
0x400e16b0: esp_netif_action_start at /home/oetelaar/esp/esp-idf/components/esp_netif/esp_netif_handlers.c:32
D (11828) esp_netif_handlers: esp_netif action has started with netif0x3ffc7010 from event_id=0
D (11836) esp-netif_lwip-ppp: esp_netif_start_ppp: Starting PPP connection: 0x3ffc73d8
ppp_connect[1]: holdoff=0
ppp phase changed[1]: phase=3
D (11849) esp-netif_lwip-ppp: Phase Start
pppos_connect: unit 1: connecting
ppp_start[1]
ppp phase changed[1]: phase=6
D (11860) esp-netif_lwip-ppp: Phase Establish
pppos_send_config[1]: out_accm=FF FF FF FF
ppp_send_config[1]
pppos_recv_config[1]: in_accm=FF FF FF FF
ppp_recv_config[1]
ppp: auth protocols: PAP=1 CHAP=0 CHAP_MD5=0 CHAP_MS=0 CHAP_MS2=0
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x9dcc9c59> <pcomp> <accomp>]
pppos_write[1]: len=24
ppp_start[1]: finished
D (11892) esp_netif_lwip: check: remote, if=0x3ffc7010 fn=0x400e2e30
0x400e2e30: esp_netif_update_default_netif_lwip at /home/oetelaar/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163
D (11899) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffc7010
D (11908) esp_netif_lwip: call api in lwip: ret=0x0, give sem
pppos_input[1]: got 99 bytes
rcvd [LCP ConfReq id=0x0 <asyncmap 0x0> <auth chap MD5> <magic 0xd1320fb0> <pcomp> <accomp>]
sent [LCP ConfNak id=0x0 <auth pap>]
pppos_write[1]: len=12
rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x9dcc9c59> <pcomp> <accomp>]
pppos_input[1]: got 52 bytes
rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <auth pap> <magic 0xd1320fb0> <pcomp> <accomp>]
sent [LCP ConfAck id=0x1 <asyncmap 0x0> <auth pap> <magic 0xd1320fb0> <pcomp> <accomp>]
pppos_write[1]: len=28
netif_set_mtu[1]: mtu=1500
pppos_send_config[1]: out_accm=0 0 0 0
ppp_send_config[1]
pppos_recv_config[1]: in_accm=0 0 0 0
ppp_recv_config[1]
ppp phase changed[1]: phase=7
D (11989) esp-netif_lwip-ppp: Phase Authenticate
sent [PAP AuthReq id=0x1 user="KPN" password="GPRS"]
pppos_write[1]: len=17
pppos_input[1]: got 33 bytes
rcvd [LCP DiscReq id=0x2 magic=0xd1320fb0]
rcvd [PAP AuthAck id=0x1 ""]
PAP authentication succeeded
ppp phase changed[1]: phase=9
D (12018) esp-netif_lwip-ppp: Phase Network
ccp_set[1]: is_open=1, is_up=0, receive_method=0, transmit_method=0
sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
pppos_input[1]: got 34 bytes
rcvd [IPCP ConfNak id=0x1 <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14> < 82 06 0a 0b 0c 0d> < 84 06 0a 0b 0c 0e>]
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
sent [IPV6CP ConfReq id=0x1 <addr fe80::e4a6:9094:0c1e:6149>]
pppos_write[1]: len=18
sent [IPCP ConfReq id=0x2 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 10.11.12.13> <ms-dns2 10.11.12.14>]
pppos_write[1]: len=32
IPV6CP: timeout sending Config-Requests
IPCP: timeout sending Config-Requests
ppp phase changed[1]: phase=11
D (73052) esp-netif_lwip-ppp: Phase Terminate
ccp_set[1]: is_open=0, is_up=0, receive_method=0, transmit_method=0
ppp phase changed[1]: phase=6
D (73060) esp-netif_lwip-ppp: Phase Establish
pppos_send_config[1]: out_accm=FF FF FF FF
ppp_send_config[1]
pppos_recv_config[1]: in_accm=0 0 0 0
ppp_recv_config[1]
sent [LCP TermReq id=0x2 "No network protocols running"]
pppos_write[1]: len=36
sent [LCP TermReq id=0x3 "No network protocols running"]
pppos_write[1]: len=36
ppp phase changed[1]: phase=12
D (85082) esp-netif_lwip-ppp: Phase Disconnect
Connection terminated.
ppp_link_terminated[1]
ppp_link_end[1]
ppp phase changed[1]: phase=0
D (85086) esp-netif_lwip-ppp: Phase Dead
I (85090) esp-netif_lwip-ppp: Connection lost
D (85095) event: running post IP_EVENT:6 with handler 0x400db1cc and context 0x3ffb0ec4 on loop 0x3ffbc184
0x400db1cc: on_ip_event at /home/oetelaar/esp/intercom_minimal/main/app_ppp.c:200
ppp_link_terminated[1]: finished.
D (85105) pppos_example: IP event! 6
I (85111) pppos_example: Modem Disconnect from PPP Server
D (85117) event: running post IP_EVENT:6 with handler 0x400e1898 and context 0x3ffc8b08 on loop 0x3ffbc184
0x400e1898: esp_netif_action_disconnected at /home/oetelaar/esp/esp-idf/components/esp_netif/esp_netif_handlers.c:91
D (85127) esp_netif_handlers: esp_netif action disconnected with netif0x3ffc7010 from event_id=6
D (85136) esp_netif_lwip: check: remote, if=0x3ffc7010 fn=0x400e2154
0x400e2154: esp_netif_down_api at /home/oetelaar/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1125
D (85142) esp_netif_lwip: esp_netif_down_api esp_netif:0x3ffc7010
D (85149) esp_netif_lwip: check: local, if=0x3ffc7010 fn=0x400e2e30
0x400e2e30: esp_netif_update_default_netif_lwip at /home/oetelaar/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163
D (85155) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffc7010
D (85162) esp_netif_lwip: call api in lwip: ret=0x0, give sem
pppos_input[1]: got 14 bytesThe crux might be here : IPCP: timeout sending Config-Requests
I investigate further.
JonathanJol
commented
4 years ago I had a similar problem using Nimbelink's BG96 modem, it would start the PPP connection, but I was never able to get IP data.
After quite some time reading and trying other things like just sending UART AT commands, I realized that the modem had flow control enabled by default, so I just turned on HW flow control in the example code and everything worked as intended after that, I hope this information can help anybody with similar problems.
devUsama
commented
3 years ago Issue still exists with the espidf-v4.2 example
david-cermak
commented
3 years ago I'm sorry, i've been neglecting this issue, as it's a bit difficult to say whether the connection issue is or is not on IDF side (SIM800L is largely obsolete and won't work in many countries, getting the IP address depends on the mobile operator, setting the APN, etc). We're going to introduce a new modem/console example in IDF which would just propagate the AT commands from the esp-console to the device. This should help us to tell apart the operator connection issues from PPPoS problems (if the connection succeeds via command line mode but fails in PPP mode is a clear indication of pppos/esp-modem issue).
As for the current status of the PPPoS example, the only outstanding issue is in clean exit of the data mode (https://github.com/espressif/esp-idf/issues/6024, also mentioned above I think) -- master.
v4.2 needs the same patch (exit data mode) plus backport of https://github.com/espressif/esp-idf/commit/e8834b66c583fdca31ef006d2a5cdb1e1af171dev4.1 also the same patch and this UART Tout fixI will revisit this issue when we have the console app ready.
svenehlers
commented
3 years ago I have the same issue. Does anybody have a workaround for this?
david-cermak
commented
3 years ago @svenehlers Please make sure you've correctly configured the APN (in the project configuration menu)
(Top) → Component config → ESP-MODEM
Set Access Point Name (APN)Also, please check with your operator that G2 connectivity is supported and enabled.
All issues mentioned above have been fixed and the pppos-client should work as expected. We'd still keep this open, until the console application mentioned above is ready.
For troubleshooting I'd suggest enabling PPP debug messages in lwip menu, enabling phase events and sharing your debug log. Although it might be hard to tell the connectivity and cellular issues apart, it might give us some pointers, at least.
david-cermak
commented
3 years ago We're going to close this issue as noted previously. There's no update from reporters on setting APN or checking for G2/GSM connectivity. Also the modem console application is now available as an example to the esp_modem component. Users can play with the device using the console app to check for connectivity issues and settings runtime.
Please feel free to reopen this if the console app could connect but pppos example won't get an IP.
Arthedian
commented
2 years ago @david-cermak I just resolved the problem I had at the beginning. Not sure if the problem is with the chip or the library. At the begging I am hardware resetting the chip (5s down, 5s up), then I cannot get the ip address. But if instead of 5 seconds waiting before connecting I will wait 15 seconds, than everything is working.
Environment
git describe --tagsto find it): v4.1-dev-1757-g826b9f638xtensa-esp32-elf-gcc --versionto find it): (crosstool-NG esp-2019r2) 8.2.0Problem Description
I am using some old PPPOS_client example (some v4.0, but not the latest), where if I have GSM signal, it will connect to the network and I can connect to the internet without problem. I had some other issues with it, so I updated esp idf to the newest version, and now pppos_client is not working. ESP32 wont receive IP address from the GSM network.
Expected Behavior
work corectly and download things from the internet.
Actual Behavior
THE ESP32 wont receive IP address from the GSM network and it will fail to connect through the PPP network.
Steps to reproduce
Debug Logs