esp-iot-solution
esp-iot-solution copied to clipboard
espressif
hang up and can not access internet after certain time with usb_cdc_4g_module (AEGHB-841)
Answers checklist.
- [X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
- [X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
- [X] I have searched the issue tracker for a similar issue and not found a similar issue.
IDF version.
idf5.2.2
Espressif SoC revision.
esp32s3
Operating System used.
Windows
How did you build your project?
Command line with Make
If you are using Windows, please specify command line type.
CMD
Development Kit.
esp32s3
Power Supply used.
External 5V
What is the expected behavior?
I have tested idf 5.2.2, 5.3.1 with or without PSRAM support, when PSRAM enabled, I also tested "allocate memories of wifi and LWIP in SPRAM first" and "allow .bss in external" etc. but the result is similar:
- If I used my phone to connect the router, and view viedo stream, it will hang up after around 5 minutes, and then you can not access any internet.
- If I used my phone to connect the router, and not view viedo stream, but visit internet not heavily, it will hang up after a couple of hours, and then you can not access any internet.
What is the actual behavior?
it hangs up.
Steps to reproduce.
A log is like below, but it not always reports "esp-netif_lwip-ppp: pppos_input_tcpip failed with -1" before hanging up.
Debug Logs.
I (4901) IOT_USBH: Set Device Configuration = 1
I (4906) IOT_USBH: Set Device Configuration Done
I (4911) IOT_USBH: Pipe init succeed, addr: 84
I (4916) IOT_USBH: Pipe init succeed, addr: 02
I (4922) USB_HCDC: CDC Device Connected
I (4926) esp-modem: --------- Modem PreDefined Info ------------------
I (4933) esp-modem: Model: User Defined
I (4938) esp-modem: Modem itf: IN Addr:0x84, OUT Addr:0x02
I (4944) esp-modem: ----------------------------------------------------
I (4952) USB_HCDC: rx0 flush -19 = 19
I (4952) modem_board: DTE reconnect, reconnecting ...
I (5961) modem_board: reconnect after 5s...
I (6961) modem_board: reconnect after 4s...
I (7961) modem_board: reconnect after 3s...
I (8961) modem_board: reconnect after 2s...
I (9961) modem_board: reconnect after 1s...
I (9961) modem_board: Modem state STAGE_SYNC, Start
I (9975) modem_board: Network Auto reconnecting ...
W (9975) 4g_main: Modem Board Event: Network disconnected
I (9975) modem_board: Modem state STAGE_SYNC, Success!
I (10081) modem_board: Modem state STAGE_CHECK_SIM, Start
I (10084) modem_board: SIM Card Ready
I (10084) 4g_main: Modem Board Event: SIM Card Connected
I (10084) modem_board: Modem state STAGE_CHECK_SIM, Success!
I (10192) modem_board: Modem state STAGE_CHECK_SIGNAL, Start
I (10195) modem_board: Signal quality: rssi=27, ber=0
I (10195) modem_board: Modem state STAGE_CHECK_SIGNAL, Success!
I (10299) modem_board: Modem state STAGE_CHECK_REGIST, Start
I (10302) modem_board: Network registered, Operator: "46011"
I (10302) modem_board: Modem state STAGE_CHECK_REGIST, Success!
I (10407) modem_board: Modem state STAGE_START_PPP, Start
I (10539) modem_board: Modem state STAGE_START_PPP, Success!
W (10540) modem_board: Modem event! 0
I (10554) esp-netif_lwip-ppp: Connected
I (10554) modem_board: IP event! 6
I (10554) modem_board: Modem Connected to PPP Server
I (10557) modem_board: ppp ip: 10.137.25.246, mask: 255.255.255.255, gw: 10.64.64.64
I (10566) modem_board: Main DNS: 222.66.251.8
I (10571) modem_board: Backup DNS: 116.236.159.8
I (10576) esp-modem-netif: PPP state changed event 0: (NETIF_PPP_ERRORNONE)
I (10584) 4g_router_server: ssid : Can't find in NVS!
I (10589) 4g_router_server: password : Can't find in NVS!
I (10595) 4g_router_server: auth_mode : Can't find in NVS!
I (10602) 4g_router_server: channel : Can't find in NVS!
I (10608) 4g_router_server: hide_ssid : Can't find in NVS!
I (10614) 4g_router_server: bandwidth : Can't find in NVS!
I (10620) 4g_router_server: max_connection : Can't find in NVS!
I (10639) modem_board: Modem state STAGE_WAIT_IP, Start
I (10639) 4g_main: Modem Board Event: Network connected
I (10639) modem_board: Modem state STAGE_WAIT_IP, Success!
I (10673) 4g_router_server: Partition size: total: 956561, used: 184736
I (10673) 4g_router_server: Starting server on port: '80'
I (10677) 4g_router_server: Registering URI handlers
I (10681) 4g_router_server: Starting webserver
I (10687) pp: pp rom version: e7ae62f
I (10691) net80211: net80211 rom version: e7ae62f
I (10697) wifi:wifi driver task: 3fcc6710, prio:23, stack:6656, core=0
I (10711) wifi:wifi firmware version: ccaebfa
I (10711) wifi:wifi certification version: v7.0
I (10711) wifi:config NVS flash: enabled
I (10714) wifi:config nano formating: disabled
I (10718) wifi:Init data frame dynamic rx buffer num: 32
I (10723) wifi:Init static rx mgmt buffer num: 5
I (10728) wifi:Init management short buffer num: 32
I (10732) wifi:Init dynamic tx buffer num: 32
I (10737) wifi:Init tx cache buffer num: 32
I (10740) wifi:Init static tx FG buffer num: 2
I (10744) wifi:Init static rx buffer size: 1600
I (10749) wifi:Init static rx buffer num: 10
I (10753) wifi:Init dynamic rx buffer num: 32
I (10757) wifi_init: accept mbox: 6
I (10761) wifi_init: tcpip mbox: 32
I (10765) wifi_init: udp mbox: 6
I (10769) wifi_init: tcp mbox: 6
I (10773) wifi_init: tcp tx win: 5760
I (10777) wifi_init: tcp rx win: 5760
I (10782) wifi_init: tcp mss: 1440
I (10786) wifi_init: WiFi/LWIP prefer SPIRAM
I (10791) wifi_init: WiFi IRAM OP enabled
I (10795) wifi_init: WiFi RX IRAM OP enabled
I (10800) wifi_init: LWIP IRAM OP enabled
I (10805) phy_init: phy_version 680,a6008b2,Jun 4 2024,16:41:10
I (10842) wifi:mode : softAP (24:58:7c:d0:6b:91)
I (10845) wifi:Total power save buffer number: 16
I (10845) wifi:Init max length of beacon: 752/752
I (10846) wifi:Init max length of beacon: 752/752
I (10850) modem_wifi: Wi-Fi AP started
I (10850) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (10867) wifi:Total power save buffer number: 16
I (10868) modem_wifi: softap ssid: esp_4g_router password: 12345678
I (10869) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (10883) modem_wifi: ap dns addr(default): 8.8.8.8
I (10889) 4g_main: changed: ap dns addr (auto): 222.66.251.8
I (10895) 4g_main: Ping addr 8.8.8.8 Restart..
I (11048) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=147 ms
I (20900) 4g_main: Ping addr 8.8.8.8 Restart..
I (21031) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=130 ms
I (23985) wifi:new:<6,2>, old:<6,2>, ap:<6,2>, sta:<255,255>, prof:6, snd_ch_cfg:0x0
I (23985) wifi:station: 72:64:f8:6d:c2:e2 join, AID=1, bgn, 40D
I (24026) 4g_router_server: station 72:64:f8:6d:c2:e2 join, AID=1
I (24026) 4g_router_server: 7264f86dc2e2 : Can't find in NVS!
I (24029) modem_wifi: NAT is enabled
I (24033) 4g_main: Modem Board Event: Station connected
I (24252) esp_netif_lwip: DHCP server assigned IP to a client, IP is: 192.168.4.2
I (24252) modem_board: IP event! 2
I (24254) 4g_router_server: 7264f86dc2e2 : Can't find in NVS!
I (24260) 4g_router_server: MAC is 72:64:f8:6d:c2:e2, IP is 192.168.4.2, start_time is 23163366
I (24269) modem_wifi: Get IP addr
E (24985) 4g_router_server: No auth header received
E (24987) 4g_router_server: rest_common_get_handler(901): not login yet
I (30900) 4g_main: Ping addr 8.8.8.8 Restart..
I (30963) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=62 ms
E (33824) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33827) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33830) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33832) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33840) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33845) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33853) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33860) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33865) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
E (33874) esp-netif_lwip-ppp: pppos_input_tcpip failed with -1
I (40900) 4g_main: Ping addr 8.8.8.8 Restart..
W (42900) 4g_main: From 8.8.8.8 icmp_seq=1 timeout
I (50900) 4g_main: Ping addr 8.8.8.8 Restart..
I (52015) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=1114 ms
I (60900) 4g_main: Ping addr 8.8.8.8 Restart..
I (61438) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=537 ms
I (70900) 4g_main: Ping addr 8.8.8.8 Restart..
W (72900) 4g_main: From 8.8.8.8 icmp_seq=1 timeout
I (80900) 4g_main: Ping addr 8.8.8.8 Restart..
I (80900) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=112 time=0 ms
I (90901) 4g_main: Ping addr 8.8.8.8 Restart..
W (92901) 4g_main: From 8.8.8.8 icmp_seq=1 timeout
I (100901) 4g_main: Ping addr 8.8.8.8 Restart..
W (102901) 4g_main: From 8.8.8.8 icmp_seq=1 timeout
More Information.
No response
This seems to be where the program has stalled. The example has disabled the interrupt watchdog by default. You need to enable both the interrupt watchdog and the task watchdog, and then test again. Please provide me with the subsequent logs.
CONFIG_ESP_TASK_WDT_EN=y
CONFIG_ESP_INT_WDT=y
This seems to be where the program has stalled. The example has disabled the interrupt watchdog by default. You need to enable both the interrupt watchdog and the task watchdog, and then test again. Please provide me with the subsequent logs.
CONFIG_ESP_TASK_WDT_EN=y CONFIG_ESP_INT_WDT=y
hello, can you help me for the similar problem? the log show me can not ping reach to 8.8.8.8 successfully, and "device 1 gone, usb disconnected" log printed time after time.
this is my log: I (107104) 4g_main: 0.00 724 modem_daemon 6
I (107104) 4g_main: 64 bytes from 8.8.8.8 icmp_seq=1 ttl=110 time=138 ms
I (107116) 4g_main: Free heap=183276 Free mini=120832 bigst=180092, internal=175504 bigst=120832 D (112964) USBH: Processing actions 0x17 D (112964) USBH: Default pipe device 1 E (112964) USBH: Device 1 gone D (112965) USBH_CDC: Device suddenly disconnected D (112980) USBH: Processing actions 0x20 D (112980) event: running post MODEM_BOARD_EVENT:1 with handler 0x4200b2b8 and context 0x3fcb992c on loop 0x3fcaa06c --- 0x4200b2b8: on_modem_event at /mnt/d/env/robot/esp32/arduino-dev/my_code/person_detect/esp-iot-solution/examples/usb/host/usb_cdc_4g_module/main/app_main.c:144
D (112980) modem_board: Handling bits = 00A0, stage = 8, retry = 0 W (112984) 4g_main: Modem Board Event: USB disconnected I (112990) modem_board: Modem state STAGE_DTE_LOSS, Start W (113002) esp-modem: Waiting exit the PPP mode gracefully D (113003) event: running post ESP_MODEM_EVENT:3 with handler 0x42038228 and context 0x3fcb97d8 on loop 0x3fcaca9c --- 0x42038228: esp_netif_action_stop at /home/cjj/env/esp/esp-idf/components/esp_netif/esp_netif_handlers.c:30
I ( with netif0x3fcb826c from event_id=3 D (112980) USBH: Freeing device 1 D (113034) esp-netif_lwip-ppp: esp_netif_stop_ppp: Stopped PPP connection: 0x3fcb84dc D (113045) esp-netif_lwip-ppp: Phase Terminate D (113050) event: running post NETIF_PPP_STATUS:267 with handler 0x420174a8 and context 0x3fcb9890 on loop 0x3fcaa06c --- 0x420174a8: on_ppp_changed at /mnt/d/env/robot/esp32/arduino-dev/my_code/person_detect/esp-iot-solution/components/usb/iot_usbh_modem/src/esp_modem_netif.c:73
D (113050) esp-netif_lwip-ppp: Phase Network D (113065) event: p_netif_lwip: esp_netif_internal_dhcpc_cb lwip-netif:0x3fcb82f0 D (113082) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fcb826c D (113090) esp_netif_lwip: if0x3fcb826c start ip lost tmr: interval=120 D (113096) esp-netif_lwip-ppp: Phase Establish D (113101) event: running post NETIF_PPP_STATUS:262 with handler 0x420174a8 and context 0x3fcb9890 on loop 0x3fcaa06c --- 0x420174a8: on_ppp_changed at /mnt/d/env/robot/esp32/arduino-dev/my_code/person_detect/esp-iot-solution/components/usb/iot_usbh_modem/src/esp_modem_netif.c:73
E (113101) USBH_CDC: usbh_cdc_write_bytes(969): Device is not connected D (113050) USBH: Device all free D (113119) esp_netif_lwip: check: remote, if=0x3fcb826c fn=0x420a191c --- 0x420a191c: esp_netif_update_default_netif_lwip at /home/cjj/env/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:327
D (113129) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcb826c D (113136) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (113141) event: running post ESP_MODEM_EVENT:3 with handler 0x42014230 and context 0x3fcb98c4 on loop 0x3fcaca9c --- 0x42014230: on_modem_event at /mnt/d/env/robot/esp32/arduino-dev/my_code/person_detect/esp-iot-solution/components/usb/iot_usbh_modem/src/usbh_modem_board.c:278
D (113142) HUB: Recovering root port W (113152) modem_board: Modem event! 3 D (114130) HUB: Root port reset D (114130) HUB: Stage done: START D (114131) HUB: Stage done: GET_SHORT_DEV_DESC UB: Stage done: CHECK_SHORT_DEV_DESC D (114195) HUB: Stage done: SECOND_RESET D (114195) HUB: Stage done: SET_ADDR D (114195) HUB: Stage done: CHECK_ADDR D (114206) HUB: Stage done: ECOVERY D (114206) HUB: Stage done: GET_FULL_DEV_DESC D (114206) HUB: Stage done: CHECK_FULL_DEV_DESC D (114209) HUB: Stage done: GET_SHORT_CONFI done: GET_FULL_CONFIG_DESC D (114223) HUB: Stage done: CHECK_FULL_CONFIG_DESC D (114228) HUB: Stage done: SET_CONFIG D (114232) HUB: Stage done: CHECK_CONFIG D (114236) HUB: Stage done: GET_SHORT_LANGID_TABLE D (114241) HUB: Stage done: CHECK_SHORT_LANGID_TABLE D (114246) HUB: Stage done: GET_FULL_LANGID_TABLE D (114251) HUB: Stage done: CHECK_FULL_LANGID_TABLE D (114256) HUB: Stage done: GET_SHORT_MANU_STR_DESC D (114261) HUB: Stage done: CHECK_SHORT_MANU_STR_DESC B: Stage done: CHECK_FULL_MANU_STR_DESCNU_STR_DESC D (114276) HUB: Stage done: GET_SHORT_PROD_STR_DESC D (114281) HUB: Stage done: CHECK_SHORT_PROD_STR_DESC D (114286) HUB: Stage done: GET_FULL_PROD_STR_DESC D (114291) HUB: Stage done: CHECK_FULL_PROD_STR_DESC D (114296) HUB: Stage done: GET_SHORT_SER_STR_DESC D (114300) HUB: Stage done: CHECK_SHORT_SER_STR_DESC D (114305) HUB: Stage done: GET_FULL_SER_STR_DESC D (114310) HUB: Stage done: CHECK_FULL_SER_STR_DESC D (114315) HUB: Stage done: CLEANUP D (114319) USBH: Processing actions 0x100 D (114323) USBH: New device 1 Found OUT endpoint: 2 Found IN endpoint: 132 D (114330) USBH_CDC: in ep mps: 64 D (114334) USBH_CDC: Submitting poll for BULK IN transfer D (114339) event: running post MODEM_BOARD_EVENT:0 with handler 0x4200b2b8 and context 0x3fcb992c on loop 0x3fcaa06c --- 0x4200b2b8: on_modem_event at /mnt/d/env/robot/esp32/arduino-dev/my_code/person_detect/esp-iot-solution/examples/usb/host/usb_cdc_4g_module/main/app_main.c:144
D (114339) modem_board: Handling bits = 0120, stage = 0, retry = 0 I (114350) 4g_main: Modem Board Event: USB connected I (114356) modem_board: DTE reconnect, reconnecting ...
I (114350) USBH_CDC: Opened cdc device: 1: New device connected, address: 1 I (115367) modem_board: reconnect after 5s... D (115814) USBH_CDC: 0x3fcba020 0d 0a 5e 4d 4f 44 45 3a 20 31 37 2c 31 37 0d 0a |..^MODE: 17,17..| D (115815) USBH_CDC: 0x3fcba020 0d 0a 2b 45 5f 55 54 52 41 4e 20 53 65 72 76 69 |..+E_UTRAN Servi| D (115822) USBH_CDC: 0x3fcba030 63 65 0d 0a |ce..| D (115830) USBH_CDC: 0x3fcba020 0d 0a 2b 43 47 45 56 3a 20 4d 45 20 50 44 4e 20 |..+CGEV: ME PDN | D (115839) USBH_CDC: 0x3fcba0 41 43 54 20 31 0d 0a |ACT 1..| D (115852) USBH_CDC: 0x3fcba020 0d 0a 2b 4e 49 54 5a 3a 20 32 35 2f 30 35 2f 32 |..+NITZ: 25/05/2| D (115857) USBH_CDC: 0x3fcba030 34 2c 30 38 3a 32 36 3a 35 32 2b 33 32 2c 30 0d |4,08:26:52+32,0.| D (115867) USBH_CDC: 0x3fcba040 0a |.| I (116367) modem_board: reconnect after 4s... I (117125) 4g_main: Ping addr 8.8.8.8 Restart.. I (117126) 4g_main: Task dump
I (117126) 4g_main: Load Stack left Name PRI
I (117128) 4g_main: 0.87 216 main 1
I (117132) 4g_main: 97.55 744 IDLE 0
I (117137) 4g_main: 96.50 736 IDLE 0 09 2008 ping 2
I (117161) 4g_main: 0.01 1328 Tmr Svc 1
I (117166) 4g_main: 0.00 504 ipc1 24
I (117171) 4g_main: 00 528 ipc0 24
I (117175) 4g_main: 0.58 552 sys_evt 20
I (117180) 4g_main: 1.49 1916 usbh_cdc 5
I (117185) 4g_main: 0.05 3184 esp_timer 22
I (117190) 4g_main: 0.10 3632 wifi 23
I (117195) 4g_main: 1.35 1916 usb_lib 5
I (117200) 4g_main: 0.00 2108 httpd 5
I (117204) 4g_main: Free heap=181568 Free mini=116736 bigst=180092, internal=173796 bigst=116736 I (117367) modem_board: reconnect after 3s... I (118367) modem_board: reconnect after 2s... W (119125) 4g_main: From 8.8.8.8 icmp_seq=1 timeout
@lijunru-hub the network can connect for a while now , but disconnect after several minutes, and repeat for ever. especially when i connect the esp_4g_router, the network will keep disconnected, with a error "Device 1 gone" and "USB disconnected", can you help me for solving the problem?
This issue seems to be caused by insufficient power supply to the 4G module. When the data transmission load is high, the module restarts. Try providing additional power to see if it resolves the problem.
The current draw peaks during network attachment and high-throughput transmission. Based on your logs, it strongly resembles that scenario.
This issue seems to be caused by insufficient power supply to the 4G module. When the data transmission load is high, the module restarts. Try providing additional power to see if it resolves the problem.
Thanks for your reply. yes, the reason you said is very right, i have buy a new power for 5v 2a(the old is about 5v 500ma), and the device is no longer disconnect like before again, the program work perfectly, until today, I have encountered a new problem, see the log below.
This issue seems to be caused by insufficient power supply to the 4G module. When the data transmission load is high, the module restarts. Try providing additional power to see if it resolves the problem.
Thanks for your reply. yes, the reason you said is very right, i have buy a new power for 5v 2a(the old is about 5v 500ma), and the device is no longer disconnect like before again, the program work perfectly, until today, I have encountered a new problem, see the log below.
I delete my local source code, and clone the source code from github again, and config, build, flash, now it work perfectly again. i have no idea what misstake i have made. days ago, i have try to config to enable ipv6 for geting a global ipv6 address, but not success, so i recover the config(disable ipv6 config again), perhaps this change has caused the problem. by the way, can i get a global ipv6 address through config or add some code to my programe, and how ?