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

Wifi Stop to Work (IDFGH-2954) #4987

Closed
filzek opened this issue Mar 25, 2020 · 11 comments
Closed

Wifi Stop to Work (IDFGH-2954) #4987

filzek opened this issue Mar 25, 2020 · 11 comments

Comments

@filzek
Copy link

filzek commented Mar 25, 2020

Using Module ESP32 Wrover-B:

I (686) psram: This chip is ESP32-D0WD
I (687) spiram: Found 64MBit SPI RAM device
I (687) spiram: SPI RAM mode: flash 40m sram 40m
I (689) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (727) cpu_start: ESP-IDF: v4.2-dev-792-g6330b3345-dirty
I (1830) wifi:wifi driver task: 3ffd4c48, prio:23, stack:3584, core=0
I (1840) wifi:wifi firmware version: b88ceb8
I (1840) wifi:wifi certification version: v7.0
I (1840) wifi:config NVS flash: enabled
I (1840) wifi:config nano formating: disabled
I (1850) wifi:Init dynamic tx buffer num: 32
I (1850) wifi:Init data frame dynamic rx buffer num: 32
I (1860) wifi:Init management frame dynamic rx buffer num: 32
I (1860) wifi:Init management short buffer num: 32
I (1870) wifi:Init static tx buffer num: 16
I (1870) wifi:Init static rx buffer size: 1600
I (1870) wifi:Init static rx buffer num: 10
I (1880) wifi:Init dynamic rx buffer num: 32
I (7170) wifi:mode : sta + softAP

After 12 hours of running the Wifi seens to stop to work and report:

I (31476240) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (31476240) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31476240) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31476250) wifi:state: init -> auth (b0)
I (31476260) wifi:state: auth -> assoc (0)
I (31476270) wifi:state: assoc -> run (10)
I (31480320) wifi:state: run -> init (2a0)
I (31480320) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (31480320) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31480320) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31480330) wifi:state: init -> auth (b0)
I (31480340) wifi:state: auth -> assoc (0)
I (31480350) wifi:state: assoc -> run (10)
I (31484390) wifi:state: run -> init (2a0)
I (31484400) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (31484400) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31487810) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (31487810) wifi:state: init -> auth (b0)
I (31487820) wifi:state: auth -> assoc (0)
I (31487830) wifi:state: assoc -> run (10)
I (31491870) wifi:state: run -> init (2a0)
@github-actions github-actions bot changed the title Wifi Stop to Work Wifi Stop to Work (IDFGH-2954) Mar 25, 2020
@Alvin1Zhang
Copy link
Collaborator

@filzek Thanks for reporting, would you please help provide more details in the issue template, such as commit ID and etc? This would help us in further debugging. Thanks.

@filzek
Copy link
Author

filzek commented Mar 25, 2020

Sure,
ESP-IDF v4.2-dev-792-g6330b3345
xtensa-esp32-elf-gcc (crosstool-NG esp-2019r2) 8.2.0
esp-idf-tools-setup-2.3.exe
Windows 10 x64
Power supply 5V 1.7A extreme low ripple.

The Wifi code:

void wifi_init_apsta(const char* sta_ssid, const char* sta_pass, const char* ap_ssid, const char* ap_pass, int ap_hidden)
{
  //wifi_event_group = xEventGroupCreate();
	int isthereanywifi=0;

	ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_APSTA));
	ESP_ERROR_CHECK( esp_wifi_set_storage(WIFI_STORAGE_RAM) );

	if (ap_ssid)
	{
						isthereanywifi++;
						wifi_config_t wifi_config = {
								.ap = {
										.ssid = "",
										.ssid_len = 0,
										.max_connection = 8,
										.password = "",
										.authmode = WIFI_AUTH_WPA_WPA2_PSK
								},
						};


						strncpy((char*) wifi_config.ap.ssid, ap_ssid, sizeof(wifi_config.ap.ssid));

						if (ap_pass) {
								if (strlen(ap_pass) != 0 && strlen(ap_pass) < 8) {
										// ESP_LOGE("Global - wifi_init_apsta", "password less than 8");
										return false;
								}
								strncpy((char*) wifi_config.ap.password, ap_pass, sizeof(wifi_config.ap.password));

						}

						wifi_config.ap.ssid_hidden = ap_hidden; // 0 = show 1 = hidden


						if (strlen(ap_pass) == 0) {
					      wifi_config.ap.authmode = WIFI_AUTH_OPEN;
					  }

					  ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_AP, &wifi_config));

	}

	if (sta_ssid)
	{
		isthereanywifi++;
		wifi_config_t wifi_config2 = { 0 };
		strlcpy((char*) wifi_config2.sta.ssid, sta_ssid, sizeof(wifi_config2.sta.ssid));
		if (sta_pass) {
			strncpy((char*) wifi_config2.sta.password, sta_pass, sizeof(wifi_config2.sta.password));
		}
		wifi_config2.sta.channel = 0;

		ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_STA, &wifi_config2) );

		// ESP_LOGI("Global - wifi_init_apsta", "wifi_init_sta finished.");
		// ESP_LOGI("Global - wifi_init_apsta", "connect to ap SSID:%s password:%s", sta_ssid, sta_pass);
	}

	ESP_ERROR_CHECK(esp_wifi_start());

	if (isthereanywifi>0){
		 esp_wifi_connect();
	}


}

and the TCP:

tcpip_adapter_init();

I am not using esp_netif_init(); yet.

@liuzfesp
Copy link
Contributor

Hi @filzek, are you using the correct password?

@filzek
Copy link
Author

filzek commented Mar 25, 2020

@liuzfesp Yes, using all correct, it works for some time, and after few hours it stop to work as show above.

@filzek
Copy link
Author

filzek commented Mar 26, 2020

Extreme problematic situation simple WiFi stop to work in the latest idf and 2.3 install kit, its a complete broken to a WiFi chain, it works for a while and later start to act like this.

I (45627332) wifi:state: assoc -> run (10)
I (45637342) wifi:state: run -> init (cc00)
I (45637342) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (45640752) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45640752) wifi:state: init -> auth (b0)
I (45640772) wifi:state: auth -> assoc (0)
I (45640782) wifi:state: assoc -> run (10)
I (45644832) wifi:state: run -> init (2a0)
I (45644832) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (45644832) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45644832) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45644842) wifi:state: init -> auth (b0)
I (45644852) wifi:state: auth -> assoc (0)
I (45644862) wifi:state: assoc -> run (10)
I (45648912) wifi:state: run -> init (2a0)
I (45648912) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (45648912) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45648922) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45648922) wifi:state: init -> auth (b0)
I (45648932) wifi:state: auth -> assoc (0)
I (45648952) wifi:state: assoc -> run (10)
I (45652992) wifi:state: run -> init (2a0)
I (45652992) wifi:new:<8,0>, old:<8,2>, ap:<8,2>, sta:<8,2>, prof:8
I (45653002) wifi:new:<8,0>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45656402) wifi:new:<8,2>, old:<8,0>, ap:<8,2>, sta:<8,2>, prof:8
I (45656412) wifi:state: init -> auth (b0)
I (45656422) wifi:state: auth -> assoc (0)
I (45656432) wifi:state: assoc -> run (10)

@liuzfesp
Copy link
Contributor

Hi @filzek , according to the log, the WiFi can't reconnect successfully because 4-way-handshake is failed and the Router sends a disassociation frame to ESP32.

You can take following steps to get more debug info:

  • In $IDF_PATH/components/wpa_supplicant/include/utils/wpa_debug.h, modify the definition of wpa_printf to #define wpa_printf(level, fmt, args...) printf("wpa:"fmt, ##args);
  • make menuconfig => Components => Supplicant => Enable "Print debug message from WPA Supplicant"

Then reproduce the issue and paste the whole log here, I will analyze the log.

@liuzfesp
Copy link
Contributor

liuzfesp commented Mar 31, 2020 •
edited
Loading

Hi @filzek, do you have any update about this issue?

@filzek
Copy link
Author

filzek commented Mar 31, 2020

Hi Liuz,

After update to the latest sdk as of today the error stop to show and has successful connect, also we have removed all other logs info and seems stable and the error stop to show.

I have ask the other fw engineer to revert their machine to the same git version to reproduce the error again.

@zinke-ct-video
Copy link

zinke-ct-video commented Apr 22, 2020 •
edited
Loading

I have exactly the same issue with commit d85d3d9 (updated my local ESP-IDF folder on 2020-04-21).
With my android mobile phone everything works fine. With my lenovo laptop I have two scenarios:

  1. If the Laptop is already connected to the ESP-WiFi and then I restart the ESP, the reconnect after ESP has rebooted works fine.
  2. The laptop is not connected to the ESP-WiFi. ESP finishes booting. Laptop connects manually (I click on connect) to ESP WiFi, then the WIFI_EVENT_AP_STACONNECTED is raised several times as well as the IP_EVENT_AP_STAIPASSIGNED. After ~5 to max. ~30 reconnects the connection gets stable. A WIFI_EVENT_AP_STADISCONNECTED is never raised during this period.

My log looks as follows:

I (5693) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (5693) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (5703) WIFI-AP: WiFi station connected (total 1)
I (6713) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (6713) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (10723) wifi:station: 18:1d:ea:2c:d6:2a leave, AID = 1, bss_flags is 134242, bss:0x3ffe2334
I (10723) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (10743) wifi:new:<5,1>, old:<5,0>, ap:<5,1>, sta:<255,255>, prof:5
I (10753) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (10763) WIFI-AP: WiFi station connected (total 2)
I (11013) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (11793) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (11793) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (15793) wifi:station: 18:1d:ea:2c:d6:2a leave, AID = 1, bss_flags is 134242, bss:0x3ffe2334
I (15793) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (16493) wifi:new:<5,1>, old:<5,0>, ap:<5,1>, sta:<255,255>, prof:5
I (16493) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (16503) WIFI-AP: WiFi station connected (total 3)
I (16573) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (16583) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (16583) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (17513) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (17513) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (21513) wifi:station: 18:1d:ea:2c:d6:2a leave, AID = 1, bss_flags is 134242, bss:0x3ffe2334
I (21513) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (21543) wifi:new:<5,1>, old:<5,0>, ap:<5,1>, sta:<255,255>, prof:5
I (21543) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (21553) WIFI-AP: WiFi station connected (total 4)
I (21573) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (22563) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (22563) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U

and so on.

@HarveyRong-Esp
Copy link
Contributor

Hi @zinke-ct-video
Can you help provide Wi-Fi packets? This will facilitate further analysis of the issue.

The recommended Macbook's built-in packet capture tool does not require a packet capture card. It can be used to capture 802.11a/b/g/n/ac packets:
https://osxdaily.com/2015/04/23/sniff-packet-capture-packet-trace-mac-os-x-wireless-diagnostics/
Or you can use the tutorial on the official Espressif website to capture packets using Wireshark
https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-guides/wireshark-user-guide.html

@liuzfesp
Copy link
Contributor

Hi @zinke-ct-video

For your log:

I (16573) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (16583) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102
I (16583) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.1.102

The multiple IP_EVENT_AP_STAIPASSIGNED is expected behavior, the can happen in following scenario:

  • The ESP32 AP successfully sends DHCP ACK to the STA (such as laptop or phone etc)
  • But the STA doesn't receive the DHCP ACK and re-start the DHCP process:
    • STA sends DHCP DISCOVERY to AP
    • AP replies DHCP OFFER
    • STA sends DHCP REQUEST
    • AP replies DHCP ACK
  • After DHCP ACK is sent, the 2nd IP_EVENT_AP_STAIPASSIGNED will be displayed. The reason is that the AP has no way to know whether the STA has successfully received the DHCP ACK or NOT, what it can do is to generate IP_EVENT_AP_STAIPASSIGNED after sending the DHCP ACK.

For multiple WIFI_EVENT_AP_STACONNECTED, it has similar reason, after AP sends the last WiFi connection frame (4/4 EAPOL frame), it generates WIFI_EVENT_AP_STACONNECTED, but it don't know whether the last WiFi connection frame has been received by STA or NOT. If the STA restarts whole connection process, AP may generates multiple WIFI_EVENT_AP_STACONNECTED.

I (17513) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<255,255>, prof:5
I (17513) wifi:station: 18:1d:ea:2c:d6:2a join, AID=1, bgn, 40U
I (21513) wifi:station: 18:1d:ea:2c:d6:2a leave, AID = 1, bss_flags is 134242, bss:0x3ffe2334

For no WIFI_EVENT_AP_STADISCONNECTED, it should be a bug, we will debug it.

@liuzfesp liuzfesp mentioned this issue Jul 13, 2020
Closed
espressif-bot pushed a commit that referenced this issue Aug 16, 2020
@HarveyRong-Esp @MaxwellAlan
bugfix: fix softap mode event issue
0e24eac 
1. add sta connect again ap sent disconnect event
2. add set/get inactive time api

Closes #4401
Closes #4987
Closes #2375
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
5 participants
@liuzfesp @filzek @Alvin1Zhang @zinke-ct-video @HarveyRong-Esp