Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

PPPoS sometimes looping when trying to connect network (IDFGH-3173) #5184

Closed
Kunislaw opened this issue Apr 25, 2020 · 6 comments
Closed

PPPoS sometimes looping when trying to connect network (IDFGH-3173) #5184

Kunislaw opened this issue Apr 25, 2020 · 6 comments

Comments

@Kunislaw
Copy link

Kunislaw commented Apr 25, 2020 •
edited
Loading

Hello, I'm using the latest example from examples / pppos_client. The program can loop while getting the address, I checked older versions and it is the same. I use a roaming sim card

Modem: SIM800L

output in terminal:

I (32333) pppos_example: Modem Connect to PPP Server
I (32343) pppos_example: ~~~~~~~~~~~~~~
I (32343) pppos_example: IP          : 10.235.33.226
I (32353) pppos_example: Netmask     : 255.255.255.255
I (32353) pppos_example: Gateway     : 192.168.254.254
I (32363) pppos_example: Name Server1: 10.2.9.7
I (32363) pppos_example: Name Server2: 10.2.9.8
I (32373) pppos_example: ~~~~~~~~~~~~~~
I (32373) pppos_example: GOT ip event!!!
E (32383) event_send: invalid ip event id 5
I (32383) pppos_example: Modem Connect to PPP Server
I (32393) pppos_example: ~~~~~~~~~~~~~~
I (32393) pppos_example: IP          : 10.235.33.226
I (32403) pppos_example: Netmask     : 255.255.255.255
I (32403) pppos_example: Gateway     : 192.168.254.254
I (32413) pppos_example: Name Server1: 10.2.9.7
I (32423) pppos_example: Name Server2: 10.2.9.8
I (32423) pppos_example: ~~~~~~~~~~~~~~
I (32433) pppos_example: GOT ip event!!!
E (32433) event_send: invalid ip event id 5
I (32433) pppos_example: Modem Connect to PPP Server
I (32443) pppos_example: ~~~~~~~~~~~~~~
I (32443) pppos_example: IP          : 10.235.33.226
I (32453) pppos_example: Netmask     : 255.255.255.255
I (32463) pppos_example: Gateway     : 192.168.254.254
I (32463) pppos_example: Name Server1: 10.2.9.7
I (32473) pppos_example: Name Server2: 10.2.9.8
I (32473) pppos_example: ~~~~~~~~~~~~~~
I (32483) pppos_example: GOT ip event!!!
E (32483) event_send: invalid ip event id 5
I (32493) pppos_example: Modem Connect to PPP Server
I (32493) pppos_example: ~~~~~~~~~~~~~~
I (32503) pppos_example: IP          : 10.235.33.226
I (32503) pppos_example: Netmask     : 255.255.255.255
I (32513) pppos_example: Gateway     : 192.168.254.254
I (32513) pppos_example: Name Server1: 10.2.9.7
I (32523) pppos_example: Name Server2: 10.2.9.8
I (32523) pppos_example: ~~~~~~~~~~~~~~
I (32533) pppos_example: GOT ip event!!!
E (32533) event_send: invalid ip event id 5
I (32543) pppos_example: Modem Connect to PPP Server
I (32543) pppos_example: ~~~~~~~~~~~~~~
I (32553) pppos_example: IP          : 10.235.33.226
I (32553) pppos_example: Netmask     : 255.255.255.255
I (32563) pppos_example: Gateway     : 192.168.254.254
I (32573) pppos_example: Name Server1: 10.2.9.7
I (32573) pppos_example: Name Server2: 10.2.9.8
I (32583) pppos_example: ~~~~~~~~~~~~~~
I (32583) pppos_example: GOT ip event!!!
E (32593) event_send: invalid ip event id 5
I (32593) pppos_example: Modem Connect to PPP Server
I (32603) pppos_example: ~~~~~~~~~~~~~~
I (32603) pppos_example: IP          : 10.235.33.226
I (32613) pppos_example: Netmask     : 255.255.255.255
I (32613) pppos_example: Gateway     : 192.168.254.254
I (32623) pppos_example: Name Server1: 10.2.9.7
I (32623) pppos_example: Name Server2: 10.2.9.8
I (32633) pppos_example: ~~~~~~~~~~~~~~
I (32633) pppos_example: GOT ip event!!!
E (32643) event_send: invalid ip event id 5
I (32643) pppos_example: Modem Connect to PPP Server
I (32653) pppos_example: ~~~~~~~~~~~~~~
I (32653) pppos_example: IP          : 10.235.33.226
I (32663) pppos_example: Netmask     : 255.255.255.255
I (32663) pppos_example: Gateway     : 192.168.254.254
I (32673) pppos_example: Name Server1: 10.2.9.7
I (32673) pppos_example: Name Server2: 10.2.9.8
I (32683) pppos_example: ~~~~~~~~~~~~~~
I (32683) pppos_example: GOT ip event!!!
E (32693) event_send: invalid ip event id 5
I (32693) pppos_example: Modem Connect to PPP Server
I (32703) pppos_example: ~~~~~~~~~~~~~~
I (32703) pppos_example: IP          : 10.235.33.226
I (32713) pppos_example: Netmask     : 255.255.255.255
I (32723) pppos_example: Gateway     : 192.168.254.254
I (32723) pppos_example: Name Server1: 10.2.9.7
I (32733) pppos_example: Name Server2: 10.2.9.8
I (32733) pppos_example: ~~~~~~~~~~~~~~
I (32743) pppos_example: GOT ip event!!!
E (32743) event_send: invalid ip event id 5
I (32753) pppos_example: Modem Connect to PPP Server
I (32753) pppos_example: ~~~~~~~~~~~~~~
I (32763) pppos_example: IP          : 10.235.33.226
I (32763) pppos_example: Netmask     : 255.255.255.255
I (32773) pppos_example: Gateway     : 192.168.254.254
I (32773) pppos_example: Name Server1: 10.2.9.7
I (32783) pppos_example: Name Server2: 10.2.9.8
I (32783) pppos_example: ~~~~~~~~~~~~~~
I (32793) pppos_example: GOT ip event!!!
E (32793) event_send: invalid ip event id 5
I (32803) pppos_example: Modem Connect to PPP Server
I (32803) pppos_example: ~~~~~~~~~~~~~~
I (32813) pppos_example: IP          : 10.235.33.226
I (32813) pppos_example: Netmask     : 255.255.255.255
I (32823) pppos_example: Gateway     : 192.168.254.254
I (32823) pppos_example: Name Server1: 10.2.9.7
I (32833) pppos_example: Name Server2: 10.2.9.8
I (32843) pppos_example: ~~~~~~~~~~~~~~
I (32843) pppos_example: GOT ip event!!!
E (32843) event_send: invalid ip event id 5
I (32853) pppos_example: Modem Connect to PPP Server
I (32853) pppos_example: ~~~~~~~~~~~~~~
I (32863) pppos_example: IP          : 10.235.33.226
I (32873) pppos_example: Netmask     : 255.255.255.255
I (32873) pppos_example: Gateway     : 192.168.254.254
I (32883) pppos_example: Name Server1: 10.2.9.7
I (32883) pppos_example: Name Server2: 10.2.9.8
I (32893) pppos_example: ~~~~~~~~~~~~~~
I (32893) pppos_example: GOT ip event!!!
E (32903) event_send: invalid ip event id 5
I (32903) pppos_example: Modem Connect to PPP Server
I (32913) pppos_example: ~~~~~~~~~~~~~~
I (32913) pppos_example: IP          : 10.235.33.226
I (32923) pppos_example: Netmask     : 255.255.255.255
I (32923) pppos_example: Gateway     : 192.168.254.254
I (32933) pppos_example: Name Server1: 10.2.9.7
I (32933) pppos_example: Name Server2: 10.2.9.8
I (32943) pppos_example: ~~~~~~~~~~~~~~
I (32943) pppos_example: GOT ip event!!!
E (32953) event_send: invalid ip event id 5
I (32953) pppos_example: Modem Connect to PPP Server
I (32963) pppos_example: ~~~~~~~~~~~~~~
I (32963) pppos_example: IP          : 10.235.33.226
I (32973) pppos_example: Netmask     : 255.255.255.255
I (32973) pppos_example: Gateway     : 192.168.254.254
I (32983) pppos_example: Name Server1: 10.2.9.7
I (32993) pppos_example: Name Server2: 10.2.9.8
I (32993) pppos_example: ~~~~~~~~~~~~~~
I (33003) pppos_example: GOT ip event!!!
E (33003) event_send: invalid ip event id 5
I (33003) pppos_example: Modem Connect to PPP Server
I (33013) pppos_example: ~~~~~~~~~~~~~~
I (33013) pppos_example: IP          : 10.235.33.226
I (33023) pppos_example: Netmask     : 255.255.255.255
I (33033) pppos_example: Gateway     : 192.168.254.254
I (33033) pppos_example: Name Server1: 10.2.9.7
I (33043) pppos_example: Name Server2: 10.2.9.8
I (33043) pppos_example: ~~~~~~~~~~~~~~
I (33053) pppos_example: GOT ip event!!!
E (33053) event_send: invalid ip event id 5
I (33063) pppos_example: Modem Connect to PPP Server```
@github-actions github-actions bot changed the title PPPoS sometimes looping when trying to connect network PPPoS sometimes looping when trying to connect network (IDFGH-3173) Apr 25, 2020
@Alvin1Zhang
Copy link
Collaborator

@Kunislaw Thanks for reporting, we will look into. @david-cermak

@david-cermak
Copy link
Collaborator

Hi @Kunislaw

Could you please post the log with the below options enabled in menuconfig?

  • debug level in CONFIG_LOG_DEFAULT_LEVEL_DEBUG
  • PPP debug options in CONFIG_LWIP_PPP_DEBUG_ON

Just to make sure, was this option off -- CONFIG_LWIP_PPP_ENABLE_IPV6=n ?

@Kunislaw
Copy link
Author

Kunislaw commented Apr 29, 2020 •
edited
Loading

@david-cermak


Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:9248
ho 0 tail 12 room 4
load:0x40078000,len:14536
ho 0 tail 12 room 4
load:0x40080400,len:4388
entry 0x400806c4
I (32) boot: ESP-IDF v4.2-dev-1206-g741960d5c 2nd stage bootloader
I (32) boot: compile time 19:22:28
D (33) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (40) boot: chip revision: 1
I (44) boot_comm: chip revision: 1, min. bootloader chip revision: 0
D (51) boot.esp32: magic e9
D (54) boot.esp32: segments 04
D (57) boot.esp32: spi_mode 02
D (60) boot.esp32: spi_speed 00
D (63) boot.esp32: spi_size 02
I (66) boot.esp32: SPI Speed      : 40MHz
I (71) boot.esp32: SPI Mode       : DIO
I (76) boot.esp32: SPI Flash Size : 4MB
D (80) boot: Enabling RTCWDT(9000 ms)
I (84) boot: Enabling RNG early entropy source...
D (89) bootloader_flash: mmu set paddr=00000000 count=1 size=c00 src_addr=8000 src_addr_aligned=0
D (98) boot: mapped partition table 0x8000 at 0x3f408000
D (104) flash_parts: partition table verified, 4 entries
I (109) boot: Partition Table:
I (113) boot: ## Label            Usage          Type ST Offset   Length
D (120) boot: load partition table entry 0x3f408000
D (125) boot: type=1 subtype=2
I (128) boot:  0 nvs              WiFi data        01 02 00009000 00006000
D (136) boot: load partition table entry 0x3f408020
D (141) boot: type=1 subtype=1
I (144) boot:  1 phy_init         RF data          01 01 0000f000 00001000
D (151) boot: load partition table entry 0x3f408040
D (156) boot: type=0 subtype=0
I (159) boot:  2 factory          factory app      00 00 00010000 00100000
I (167) boot: End of partition table
D (171) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (177) esp_image: reading image header @ 0x10000
D (182) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (189) esp_image: image header: 0xe9 0x06 0x02 0x02 40081588
I (195) boot_comm: chip revision: 1, min. application chip revision: 0
I (202) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1af68 (110440) map
D (211) esp_image: free data page_count 0x00000032
D (216) bootloader_flash: mmu set paddr=00010000 count=2 size=1af68 src_addr=10020 src_addr_aligned=10000
D (268) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
I (268) esp_image: segment 1: paddr=0x0002af90 vaddr=0x3ffb0000 size=0x023d0 (  9168) load
D (272) esp_image: free data page_count 0x00000032
D (277) bootloader_flash: mmu set paddr=00020000 count=1 size=23d0 src_addr=2af90 src_addr_aligned=20000
D (290) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
I (293) esp_image: segment 2: paddr=0x0002d368 vaddr=0x40080000 size=0x00404 (  1028) load
D (302) esp_image: free data page_count 0x00000032
D (307) bootloader_flash: mmu set paddr=00020000 count=1 size=404 src_addr=2d368 src_addr_aligned=20000
D (317) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
I (324) esp_image: segment 3: paddr=0x0002d774 vaddr=0x40080404 size=0x028a4 ( 10404) load
D (332) esp_image: free data page_count 0x00000032
D (337) bootloader_flash: mmu set paddr=00020000 count=2 size=28a4 src_addr=2d774 src_addr_aligned=20000
D (351) bootloader_flash: mmu set block paddr=0x00030000 (was 0xffffffff)
I (354) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x68bb8 (428984) map
D (363) esp_image: free data page_count 0x00000032
D (367) bootloader_flash: mmu set paddr=00030000 count=7 size=68bb8 src_addr=30020 src_addr_aligned=30000
D (540) bootloader_flash: mmu set block paddr=0x00090000 (was 0xffffffff)
I (541) esp_image: segment 5: paddr=0x00098be0 vaddr=0x40082ca8 size=0x08c20 ( 35872) load
D (545) esp_image: free data page_count 0x00000032
D (550) bootloader_flash: mmu set paddr=00090000 count=2 size=8c20 src_addr=98be0 src_addr_aligned=90000
D (575) bootloader_flash: mmu set block paddr=0x000a0000 (was 0xffffffff)
D (575) boot: Calculated hash: 07f146bcbf3bdff2a3d60e33ac5afa1ba660f7a2ad3eda9101c3f5c13054eacd
D (579) bootloader_flash: mmu set paddr=000a0000 count=1 size=20 src_addr=a1810 src_addr_aligned=a0000
D (589) bootloader_flash: mmu set paddr=000a0000 count=1 size=20 src_addr=a1810 src_addr_aligned=a0000
I (605) boot: Loaded app from partition at offset 0x10000
I (605) boot: Disabling RNG early entropy source...
D (610) boot: Mapping segment 0 as DROM
D (614) boot: Mapping segment 4 as IROM
D (618) boot: calling set_cache_and_start_app
D (622) boot: configure drom and irom and start
D (627) boot: start: 0x40081588
I (630) cpu_start: Pro cpu up.
I (634) cpu_start: Application information:
I (638) cpu_start: Project name:     pppos_client
I (644) cpu_start: App version:      2fa7b2e-dirty
I (649) cpu_start: Compile time:     Apr 29 2020 19:21:49
I (655) cpu_start: ELF file SHA256:  8a5938cfdd0efa1b...
I (661) cpu_start: ESP-IDF:          v4.2-dev-1206-g741960d5c
I (668) cpu_start: Starting app cpu, entry point is 0x40081538
I (658) cpu_start: App cpu up.
I (678) heap_init: Initializing. RAM available for dynamic allocation:
I (685) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (691) heap_init: At 3FFB3E10 len 0002C1F0 (176 KiB): DRAM
I (698) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (704) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (710) heap_init: At 4008B8C8 len 00014738 (81 KiB): IRAM
I (717) cpu_start: Pro cpu start user code
I (735) spi_flash: detected chip: generic
I (736) spi_flash: flash io: dio
I (736) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (745) uart: queue free spaces: 16
I (745) nmea_parser: NMEA Parser init OK
I (755) gpio: GPIO[27]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
ppp phase changed[1]: phase=0
I (16015) uart: queue free spaces: 30
I (17165) pppos_example: Module: SIMCOM_SIM800L
I (17165) pppos_example: Operator: "IDEA Centertel"
I (17165) pppos_example: IMEI: 864713037987016
I (17165) pppos_example: IMSI: 260066010291644
I (17365) pppos_example: rssi: 15, ber: 0
I (17565) pppos_example: Battery voltage: 5003 mV
I (17765) pppos_example: Modem PPP Started
ppp_connect[1]: holdoff=0
ppp phase changed[1]: phase=3
pppos_connect: unit 1: connecting
ppp_start[1]
ppp phase changed[1]: phase=6
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
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x74c5d3fc> <pcomp> <accomp>]
pppos_write[1]: len=24
ppp_start[1]: finished
pppos_input[1]: got 72 bytes
rcvd [LCP ConfReq id=0x1 <asyncmap 0xa0000> <auth pap> <pcomp> <accomp>]
sent [LCP ConfAck id=0x1 <asyncmap 0xa0000> <auth pap> <pcomp> <accomp>]
pppos_write[1]: len=22
rcvd [LCP ConfNak id=0x1 <asyncmap 0xa0000>]
sent [LCP ConfReq id=0x2 <asyncmap 0xa0000> <magic 0x74c5d3fc> <pcomp> <accomp>]
pppos_write[1]: len=24
pppos_input[1]: got 46 bytes
rcvd [LCP ConfAck id=0x2 <asyncmap 0xa0000> <magic 0x74c5d3fc> <pcomp> <accomp>]
netif_set_mtu[1]: mtu=1500
pppos_send_config[1]: out_accm=0 0 A 0
ppp_send_config[1]
pppos_recv_config[1]: in_accm=0 0 A 0
ppp_recv_config[1]
ppp phase changed[1]: phase=7
sent [PAP AuthReq id=0x1 user="" password=""]
pppos_write[1]: len=10
pppos_input[1]: got 27 bytes
rcvd [PAP AuthAck id=0x1 ""]
PAP authentication succeeded
ppp phase changed[1]: phase=9
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
rcvd [IPCP ConfReq id=0x1 <addr 192.168.254.254>]
sent [IPCP ConfAck id=0x1 <addr 192.168.254.254>]
pppos_write[1]: len=14
pppos_input[1]: got 16 bytes
rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
pppos_write[1]: len=26
pppos_input[1]: got 28 bytes
rcvd [IPCP ConfNak id=0x2 <addr 10.224.60.38> <ms-dns1 10.2.9.7> <ms-dns2 10.2.9.8>]
sent [IPCP ConfReq id=0x3 <addr 10.224.60.38> <ms-dns1 10.2.9.7> <ms-dns2 10.2.9.8>]
pppos_write[1]: len=26
pppos_input[1]: got 28 bytes
rcvd [IPCP ConfAck id=0x3 <addr 10.224.60.38> <ms-dns1 10.2.9.7> <ms-dns2 10.2.9.8>]
sifvjcomp[1]: VJ compress enable=0 slot=0 max slot=0
sifup[1]: err_code=0
I (18645) esp-netif_lwip-ppp: Connected
I (18655) esp-netif_lwip-ppp: Name Server1: 10.2.9.7
I (18655) esp-netif_lwip-ppp: Name Server2: 10.2.9.8
I (18665) pppos_example: Modem Connect to PPP Server
local  IP address 10.224.60.38
I (18665) pppos_example: ~~~~~~~~~~~~~~
remote IP address 192.168.254.254
I (18675) pppos_example: IP          : 10.224.60.38
primary   DNS address 10.2.9.7
I (18685) pppos_example: Netmask     : 255.255.255.255
secondary DNS address 10.2.9.8
I (18695) pppos_example: Gateway     : 192.168.254.254
ppp phase changed[1]: phase=10
I (18705) pppos_example: Name Server1: 10.2.9.7
I (18705) pppos_example: Name Server2: 10.2.9.8
I (18715) pppos_example: ~~~~~~~~~~~~~~
I (18715) pppos_example: GOT ip event!!!
E (18725) event_send: invalid ip event id 5
I (18725) pppos_example: Modem Connect to PPP Server
I (18735) pppos_example: ~~~~~~~~~~~~~~
I (18735) pppos_example: IP          : 10.224.60.38
I (18745) pppos_example: Netmask     : 255.255.255.255
I (18745) pppos_example: Gateway     : 192.168.254.254
I (18755) pppos_example: Name Server1: 10.2.9.7
I (18765) pppos_example: Name Server2: 10.2.9.8
I (18765) pppos_example: ~~~~~~~~~~~~~~
I (18765) pppos_example: GOT ip event!!!
E (18775) event_send: invalid ip event id 5
I (18775) pppos_example: Modem Connect to PPP Server
I (18785) pppos_example: ~~~~~~~~~~~~~~
I (18785) pppos_example: IP          : 10.224.60.38
I (18795) pppos_example: Netmask     : 255.255.255.255
I (18805) pppos_example: Gateway     : 192.168.254.254
I (18805) pppos_example: Name Server1: 10.2.9.7
I (18815) pppos_example: Name Server2: 10.2.9.8
I (18815) pppos_example: ~~~~~~~~~~~~~~
I (18825) pppos_example: GOT ip event!!!
E (18825) event_send: invalid ip event id 5
I (18835) pppos_example: Modem Connect to PPP Server
I (18835) pppos_example: ~~~~~~~~~~~~~~
I (18845) pppos_example: IP          : 10.224.60.38
I (18845) pppos_example: Netmask     : 255.255.255.255
I (18855) pppos_example: Gateway     : 192.168.254.254
I (18855) pppos_example: Name Server1: 10.2.9.7
I (18865) pppos_example: Name Server2: 10.2.9.8
I (18865) pppos_example: ~~~~~~~~~~~~~~
I (18875) pppos_example: GOT ip event!!!
E (18875) event_send: invalid ip event id 5
I (18885) pppos_example: Modem Connect to PPP Server
I (18885) pppos_example: ~~~~~~~~~~~~~~
I (18895) pppos_example: IP          : 10.224.60.38
I (18895) pppos_example: Netmask     : 255.255.255.255
I (18905) pppos_example: Gateway     : 192.168.254.254
I (18915) pppos_example: Name Server1: 10.2.9.7
I (18915) pppos_example: Name Server2: 10.2.9.8
I (18925) pppos_example: ~~~~~~~~~~~~~~
I (18925) pppos_example: GOT ip event!!!
E (18925) event_send: invalid ip event id 5
I (18935) pppos_example: Modem Connect to PPP Server
I (18945) pppos_example: ~~~~~~~~~~~~~~
I (18945) pppos_example: IP          : 10.224.60.38
I (18955) pppos_example: Netmask     : 255.255.255.255
I (18955) pppos_example: Gateway     : 192.168.254.254
I (18965) pppos_example: Name Server1: 10.2.9.7
I (18965) pppos_example: Name Server2: 10.2.9.8
I (18975) pppos_example: ~~~~~~~~~~~~~~
I (18975) pppos_example: GOT ip event!!!
E (18985) event_send: invalid ip event id 5
I (18985) pppos_example: Modem Connect to PPP Server
I (18995) pppos_example: ~~~~~~~~~~~~~~
I (18995) pppos_example: IP          : 10.224.60.38
I (19005) pppos_example: Netmask     : 255.255.255.255
I (19005) pppos_example: Gateway     : 192.168.254.254
I (19015) pppos_example: Name Server1: 10.2.9.7
I (19015) pppos_example: Name Server2: 10.2.9.8
I (19025) pppos_example: ~~~~~~~~~~~~~~
I (19025) pppos_example: GOT ip event!!!
E (19035) event_send: invalid ip event id 5
I (19035) pppos_example: Modem Connect to PPP Server
I (19045) pppos_example: ~~~~~~~~~~~~~~
I (19045) pppos_example: IP          : 10.224.60.38
I (19055) pppos_example: Netmask     : 255.255.255.255
I (19055) pppos_example: Gateway     : 192.168.254.254
I (19065) pppos_example: Name Server1: 10.2.9.7
I (19075) pppos_example: Name Server2: 10.2.9.8
I (19075) pppos_example: ~~~~~~~~~~~~~~
I (19085) pppos_example: GOT ip event!!!
E (19085) event_send: invalid ip event id 5
I (19085) pppos_example: Modem Connect to PPP Server
I (19095) pppos_example: ~~~~~~~~~~~~~~
I (19095) pppos_example: IP          : 10.224.60.38
I (19105) pppos_example: Netmask     : 255.255.255.255
I (19115) pppos_example: Gateway     : 192.168.254.254
I (19115) pppos_example: Name Server1: 10.2.9.7
I (19125) pppos_example: Name Server2: 10.2.9.8
I (19125) pppos_example: ~~~~~~~~~~~~~~
I (19135) pppos_example: GOT ip event!!!
E (19135) event_send: invalid ip event id 5
I (19145) pppos_example: Modem Connect to PPP Server
I (19145) pppos_example: ~~~~~~~~~~~~~~
I (19155) pppos_example: IP          : 10.224.60.38
I (19155) pppos_example: Netmask     : 255.255.255.255
I (19165) pppos_example: Gateway     : 192.168.254.254
I (19165) pppos_example: Name Server1: 10.2.9.7
I (19175) pppos_example: Name Server2: 10.2.9.8
I (19175) pppos_example: ~~~~~~~~~~~~~~
I (19185) pppos_example: GOT ip event!!!
E (19185) event_send: invalid ip event id 5
I (19195) pppos_example: Modem Connect to PPP Server
I (19195) pppos_example: ~~~~~~~~~~~~~~
I (19205) pppos_example: IP          : 10.224.60.38
I (19205) pppos_example: Netmask     : 255.255.255.255
I (19215) pppos_example: Gateway     : 192.168.254.254
I (19225) pppos_example: Name Server1: 10.2.9.7
I (19225) pppos_example: Name Server2: 10.2.9.8
I (19235) pppos_example: ~~~~~~~~~~~~~~
I (19235) pppos_example: GOT ip event!!!
E (19245) event_send: invalid ip event id 5
I (19245) pppos_example: Modem Connect to PPP Server
I (19255) pppos_example: ~~~~~~~~~~~~~~
I (19255) pppos_example: IP          : 10.224.60.38
I (19265) pppos_example: Netmask     : 255.255.255.255
I (19265) pppos_example: Gateway     : 192.168.254.254
I (19275) pppos_example: Name Server1: 10.2.9.7
I (19275) pppos_example: Name Server2: 10.2.9.8
I (19285) pppos_example: ~~~~~~~~~~~~~~
I (19285) pppos_example: GOT ip event!!!
E (19295) event_send: invalid ip event id 5
I (19295) pppos_example: Modem Connect to PPP Server
I (19305) pppos_example: ~~~~~~~~~~~~~~
I (19305) pppos_example: IP          : 10.224.60.38
I (19315) pppos_example: Netmask     : 255.255.255.255
I (19315) pppos_example: Gateway     : 192.168.254.254
I (19325) pppos_example: Name Server1: 10.2.9.7
I (19325) pppos_example: Name Server2: 10.2.9.8
I (19335) pppos_example: ~~~~~~~~~~~~~~
I (19335) pppos_example: GOT ip event!!!
E (19345) event_send: invalid ip event id 5
I (19345) pppos_example: Modem Connect to PPP Server
I (19355) pppos_example: ~~~~~~~~~~~~~~
I (19355) pppos_example: IP          : 10.224.60.38
I (19365) pppos_example: Netmask     : 255.255.255.255
I (19365) pppos_example: Gateway     : 192.168.254.254
I (19375) pppos_example: Name Server1: 10.2.9.7
I (19385) pppos_example: Name Server2: 10.2.9.8
I (19385) pppos_example: ~~~~~~~~~~~~~~
I (19395) pppos_example: GOT ip event!!!
E (19395) event_send: invalid ip event id 5
I (19405) pppos_example: Modem Connect to PPP Server
I (19405) pppos_example: ~~~~~~~~~~~~~~
I (19415) pppos_example: IP          : 10.224.60.38
I (19415) pppos_example: Netmask     : 255.255.255.255
I (19425) pppos_example: Gateway     : 192.168.254.254
I (19425) pppos_example: Name Server1: 10.2.9.7
I (19435) pppos_example: Name Server2: 10.2.9.8
I (19435) pppos_example: ~~~~~~~~~~~~~~
I (19445) pppos_example: GOT ip event!!!
E (19445) event_send: invalid ip event id 5
I (19455) pppos_example: Modem Connect to PPP Server
I (19455) pppos_example: ~~~~~~~~~~~~~~
I (19465) pppos_example: IP          : 10.224.60.38
I (19465) pppos_example: Netmask     : 255.255.255.255
I (19475) pppos_example: Gateway     : 192.168.254.254
I (19475) pppos_example: Name Server1: 10.2.9.7
I (19485) pppos_example: Name Server2: 10.2.9.8
I (19485) pppos_example: ~~~~~~~~~~~~~~
I (19495) pppos_example: GOT ip event!!!
E (19495) event_send: invalid ip event id 5
I (19505) pppos_example: Modem Connect to PPP Server
I (19505) pppos_example: ~~~~~~~~~~~~~~
I (19515) pppos_example: IP          : 10.224.60.38
I (19515) pppos_example: Netmask     : 255.255.255.255
I (19525) pppos_example: Gateway     : 192.168.254.254
I (19535) pppos_example: Name Server1: 10.2.9.7
I (19535) pppos_example: Name Server2: 10.2.9.8
I (19545) pppos_example: ~~~~~~~~~~~~~~
I (19545) pppos_example: GOT ip event!!!
E (19555) event_send: invalid ip event id 5
I (19555) pppos_example: Modem Connect to PPP Server
I (19565) pppos_example: ~~~~~~~~~~~~~~
I (19565) pppos_example: IP          : 10.224.60.38
I (19575) pppos_example: Netmask     : 255.255.255.255
I (19575) pppos_example: Gateway     : 192.168.254.254
I (19585) pppos_example: Name Server1: 10.2.9.7
I (19585) pppos_example: Name Server2: 10.2.9.8
I (19595) pppos_example: ~~~~~~~~~~~~~~
I (19595) pppos_example: GOT ip event!!!
E (19605) event_send: invalid ip event id 5
I (19605) pppos_example: Modem Connect to PPP Server
I (19615) pppos_example: ~~~~~~~~~~~~~~
I (19615) pppos_example: IP          : 10.224.60.38
I (19625) pppos_example: Netmask     : 255.255.255.255
I (19625) pppos_example: Gateway     : 192.168.254.254
I (19635) pppos_example: Name Server1: 10.2.9.7
I (19635) pppos_example: Name Server2: 10.2.9.8
I (19645) pppos_example: ~~~~~~~~~~~~~~
I (19645) pppos_example: GOT ip event!!!
E (19655) event_send: invalid ip event id 5
I (19655) pppos_example: Modem Connect to PPP Server
I (19665) pppos_example: ~~~~~~~~~~~~~~
I (19665) pppos_example: IP          : 10.224.60.38
I (19675) pppos_example: Netmask     : 255.255.255.255
I (19685) pppos_example: Gateway     : 192.168.254.254
I (19685) pppos_example: Name Server1: 10.2.9.7
I (19695) pppos_example: Name Server2: 10.2.9.8
I (19695) pppos_example: ~~~~~~~~~~~~~~
I (19705) pppos_example: GOT ip event!!!
E (19705) event_send: invalid ip event id 5
I (19715) pppos_example: Modem Connect to PPP Server
I (19715) pppos_example: ~~~~~~~~~~~~~~
I (19725) pppos_example: IP          : 10.224.60.38
I (19725) pppos_example: Netmask     : 255.255.255.255
I (19735) pppos_example: Gateway     : 192.168.254.254
I (19735) pppos_example: Name Server1: 10.2.9.7
I (19745) pppos_example: Name Server2: 10.2.9.8

image

@david-cermak
Copy link
Collaborator

@Kunislaw Thanks for sharing the log and related configuration!
This looks like a bug in the default connection handler. Could you please try to apply this patch and see if that helps fixing the issue?
0001-esp_netif-fix-default-connect-handler-to-check-dhcpc.patch.txt

Thanks!

@Kunislaw
Copy link
Author

Kunislaw commented May 1, 2020 •
edited
Loading

@david-cermak
Now it looks like everything is working, but I get this a dhcpc error

I (23714) pppos_example: Modem Connect to PPP Server
local  IP address 10.198.18.159
I (23714) pppos_example: ~~~~~~~~~~~~~~
remote IP address 192.168.254.254
I (23724) pppos_example: IP          : 10.198.18.159
primary   DNS address 10.1.9.7
I (23734) pppos_example: Netmask     : 255.255.255.255
secondary DNS address 10.1.9.8
I (23744) pppos_example: Gateway     : 192.168.254.254
ppp phase changed[1]: phase=10
I (23754) pppos_example: Name Server1: 10.1.9.7
I (23754) pppos_example: Name Server2: 10.1.9.8
I (23764) pppos_example: ~~~~~~~~~~~~~~
I (23764) pppos_example: GOT ip event!!!
E (23774) esp_netif_handlers: esp_netif_action_connected 50 connected action dhcpc failed ret=0x102
I (23784) pppos_example: MQTT other event id: 7
pppos_netif_output[1]: proto=0x21, len = 61
pppos_netif_output[1]: proto=0x21, len = 61
pppos_input[1]: got 49 bytes
pppos_input[1]: got 337 bytes
ppp_input[1]: ip in pbuf len=380
pppos_netif_output[1]: proto=0x21, len = 44
pppos_input[1]: got 260 bytes
pppos_input[1]: got 127 bytes
ppp_input[1]: ip in pbuf len=380
pppos_netif_output[1]: proto=0x21, len = 56
pppos_input[1]: got 49 bytes
ppp_input[1]: ip in pbuf len=44
I (24444) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
pppos_netif_output[1]: proto=0x21, len = 40
pppos_netif_output[1]: proto=0x21, len = 61
pppos_input[1]: got 95 bytes
ppp_input[1]: ip in pbuf len=40
ppp_input[1]: ip in pbuf len=44
I (24844) pppos_example: MQTT_EVENT_CONNECTED
pppos_netif_output[1]: proto=0x21, len = 63
I (24844) pppos_example: sent subscribe successful, msg_id=35384
pppos_input[1]: got 51 bytes
ppp_input[1]: ip in pbuf len=45
I (25194) pppos_example: MQTT_EVENT_SUBSCRIBED, msg_id=35384
pppos_netif_output[1]: proto=0x21, len = 71
I (25194) pppos_example: sent publish successful, msg_id=0
pppos_input[1]: got 76 bytes
ppp_input[1]: ip in pbuf len=71
I (25494) pppos_example: MQTT_EVENT_DATA
TOPIC=/topic/esp-pppos
DATA=esp32-pppos
pppos_netif_output[1]: proto=0x21, len = 40

@david-cermak
Copy link
Collaborator

@Kunislaw Thanks for testing the patch and sharing the result. This is a bug in IDF esp-netif component. Please keep the issue open, will be closed upon merging and publishing a fix.

PS: You may use this fix and ignore the error message before it gets fixed properly (the dhcpc failed ret=0x102 error won't appear in the final log, just wanted to see what was happening at your end)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Kunislaw @david-cermak @Alvin1Zhang