Wifi disconnects and is unable to reconnect with WIFI_REASON_MIC_FAILURE code (IDFGH-5142) #6920
Comments
github-actions
bot
changed the title
|
Hi @robertoimai , What is the encryption method of router? |
|
WPA2-PSK |
|
Hi @roamingthings , Can you give me a detailed log? You need to enable the following options. |
|
This is the new sdkconfig I (10738) WIFI: Connected to wifi network Azena F |
|
Hi @robertoimai , The WiFi connection failed four handshakes. |
|
My mistake.... D (12088) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120> D (12218) wifi:profile match: ss_state=0x7 D (12238) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0> D (12258) wifi:profile match: ss_state=0x7 D (12318) wifi:profile match: ss_state=0x7 D (12788) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (12788) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (12788) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (12798) wifi:recv auth: seq=2, status=0 D (12828) wpa: EAPOL-Key type=2 D (12838) wpa: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack) D (12838) wpa: key_length=16 key_data_length=0 D (12848) wpa: WPA: RX EAPOL-Key - hexdump(len=99): D (12888) wpa: RSN: msg 1/4 key data - hexdump(len=0): D (12898) wpa: WPA: PMK - hexdump(len=32):
D (12958) wpa: WPA: TX EAPOL-Key - hexdump(len=121): D (13018) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (13028) wpa: IEEE 802.1X RX: version=2 type=3 length=199 D (13028) wpa: EAPOL-Key type=2 D (13038) wpa: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr) D (13048) wpa: key_length=16 key_data_length=104 D (13048) wpa: WPA: RX EAPOL-Key - hexdump(len=203): D (13138) wpa: WPA: No WPA/RSN IE for this AP known. Trying to get from scan results D (13148) wpa: WPA: Found the current AP from updated scan results D (13148) wpa: tx 4/4 txcb_flags=8192 D (13158) wpa: WPA Send EAPOL-Key 4/4 D (13158) wpa: WPA: TX EAPOL-Key - hexdump(len=99): D (13208) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 D (13218) wpa: WPA: Installing PTK to the driver. D (13218) wpa: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32). D (13228) wpa: WPA: Key negotiation completed with cc:32:e5:4a:72:45 [PTK=CCMP GTK=TKIP] I (13228) wifi:connected with Azena F, aid = 2, channel 2, BW20, bssid = cc:32:e5:4a:72:45 D (13248) wifi:Send sta connected event D (13288) esp_netif_handlers: esp_netif action connected with netif0x3ffe15e4 from event_id=4 D (13308) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffe15e4 D (13318) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffe15e4 D (13328) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffe15e4 I (13378) WIFI: Connected to wifi network Azena F D (14178) wifi_init_default: Got IP wifi default handler entered |
|
@robertoimai , Yes, please use this version to reproduce the issue. |
espressif-bot
added
Status: In Progress
|
This is what I get when the disconnect happens: D (3771177) wifi:stop CSA timer |
|
Hi @robertoimai , Thank you for your information. |
|
Yes, rebooting will let the esp32 reconnect and everything work fine until the next disconnect. |
|
Hi, i got the same Problem with our corporate WiFi. `D (178711) wpa: D (178711) wpa: WPA: Sending EAPOL-Key Request (error=1 pairwise=0 ptk_set=1 len=99) D (178761) wpa: WPA: Sending EAPOL-Key Request (error=1 pairwise=0 ptk_set=1 len=99) I (178831) wifi:state: run -> init (ec0) D (178841) wifi:stop CSA timer D (178941) esp_netif_lwip: esp_netif_down_api esp_netif:0x3ffd6ba0 D (178971) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffd6ba0 D (179001) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffd6ba0 D (179081) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0> I (179181) SOCKET: Setting up the SSL/TLS structure... D (179381) wifi:rsn valid: gcipher=1 ucipher=3 akm=5 |
|
@robertoimai In the last comment is a link to a similar issue that I raised. I changed my event handler to continually try to reconnect for an indefinite period of time. It takes 40-60 seconds to re-establish the connection automatically in this case. I noticed your log sample covers about 23 seconds. It would be interesting to know if you could indeed eventually reconnect. |
|
As far as I can remember, it was never able to reconnect. |
|
Any update? It seems the function to print above error log was called after MIC failure, |
|
Hi @AxelLin , After receiving a packet from the hardware, the software parses the header and throws away any wrong packets. |
|
Now there are 3 reports (running on different esp-idf version) regarding WIFI_REASON_MIC_FAILURE |
|
Hi @AxelLin , |
|
@espxiehang |
|
@AxelLin |
|
Hi @espxiehang I got similar symptoms in customer's bug report. At the moment, seems @mbratch has better chance to reproduce the MIC failure issue, see #7286 |
|
Seems the discussions are focus on WIFI_REASON_MIC_FAILURE. @robertoimai |
|
I cannot confirm nor deny. |
|
When I was using an Apple Airport Extreme (A1408), I was getting this problem regularly. I could recover by recognizing the condition in my wifi event handler and continually retrying to connect for up to 60 seconds and it would eventually reconnect. However, for that period of time, the link was obviously down. I have since changed routers. I am using now a TP-Link Archer C4000, and I have not seen the MIC problem using this router. This is why the problem is not seen by everyone. I still have my Apple Airport router I am willing to donate to someone on the ESP-IDF development team if they are willing to pursue the issue and cover the shipping of the router. :) |
|
@robertoimai @mbratch @AxelLin TKIP MIC error is used to detect attack: If a station get 2 TKIP MIC errors in a minute, it needs to disconnect from AP, and wait a minute until it can connect to the AP again. This is part of IEEE80211 standard. |
|
Hi all, I have tested master branch and I confirm the behaviour changed: right now when it disconnects sporadically with MIC failure, it reconnects while older version failed to do so (any transfer led to MIC failure); I can tell there has been an improvement, I cannot understand though the root cause of this MIC failure; My device is being tested in WPA,WPA2,WPA3,WPA2-Enterprise; but there is one AP that is configured as WPA2 CCMP+TKIP that produce this failure; I tried to replicate the same issue with another AP of different brand and "same" settings and it just works on the latter one; I am available to provide any support on this topic because at the moment is problematic and I understand is hard to replicate |
|
@Pabs84 that was basically what I had already done to work around the MIC failure. In my event handler, I detect the failure then try to reconnect. I'm able to reconnect automatically, but it takes 30-60 seconds before it's able to do so (it keeps retrying until it is successful). So the device loses wifi communications for 30-60 seconds. So in this work around fix, I would suspect the same? Do you know how long it takes it to recover from the MIC failure? |
|
@mbratch, hi, with the older version it was basically never connecting for me, because every reconnection was failing with MIC failure. Right now the fix allows me to reconnect and after let say a minute I get another MIC failure, but the reconnection works and I can stay connected until the next failure. it looks to me that there is a frame the ESP32 does not understand and is the root cause for me; however I suggest you try the latest version; I checked v4.4.2 and the fix is not there just yet though, only master |
|
most logical would be that after a minute of no traffic the AP generates a frame based on the following: |
|
@mbratch @Pabs84 The fix in #7286 (comment) just speed up to install new GTK. It can avoid some TKIP MIC error triggered by new GTK not installed but the frame encrypted with new GTK already received. It can reduce TKIP MIC error somehow. But TKIP MIC error triggered by other reason may still exist. We will try to reproduce the issues with the AP and configuration mentioned. |
|
Hi @Pabs84 Could you provide the router brand and model? We will try to reproduce this issue locally. |
|
Hi, to @mhdong: to @jack0c: Thanks for the support, I hope you can find the root cause |
|
Maybe someone can confirm this, but i just discovered that with v4.4.4 (arduino) |
espressif-bot
added
Status: Opened
@Pabs84 |
Hi @AxelLin, I have recently updated to ESP-IDF v5.0.1 and we are in the process of testing it. I will let you know if I still sporadically get MIC errors. |
|
Hi @AxelLin, I confirm that in rare conditions I can still get MIC errors. I have updated from ESP-IDF v5.0.1 to ESP-IDF v5.0.2 to check if the latest stable FW fix this with no luck. The strange thing is that it worked for weeks with no issues, and recently it stopped from working. The issue triggers within 10 seconds after a good connection. Traffic is fine until the sudden disconnection. I guess there is something on my network that triggers this, so my suggestion is to not test it as point to point. the settings are CCMP and group cipher is TKIP, which seems (with my ingenuity) to be the root cause. |
|
@Pabs84 |
I am sorry, it did happen, but I cannot understand how to replicate this at will. If I ever manage to get my hands on the logs will give you more info. |
|
Hi @AxelLin, I have the logs with MIC_FAILURE. Can we continue using PMs? |
Sorry, I don't work for espressif. |
|
Hi @Pabs84 Please help upload the log with NIC_FAILURE to github. |
|
@mhdong Hi, I will not share logs with plaintext keys publicly in principle; I can share with espressif employees using PMs. |
|
hi, @Pabs84, you can send it to the following email [email protected] and include your LOG. Please make sure to mention the GitHub link and provide a brief description in the email. Alternatively, you can notify me (@mention) after sending the email, that we can get the information as soon as possible |
|
hi @Pabs84 I have received your e-mail, thanks for your sharing, we will analyze as soon as possible. |
espressif-bot
added
Status: Reviewing
@Xiehanxin Could you share your analysis result? |
|
Hi @robertoimai Issue solved with faf4fd2 |
Environment
git describe --tagsto find it): v4.2xtensa-esp32-elf-gcc --versionto find it): xtensa-esp32-elf-gcc (crosstool-NG esp-2020r3) 8.4.0Problem Description
Module is disconnecting from wifi with reason code 14 (WIFI_REASON_MIC_FAILURE).
Any attempt to reconnect will also fail.
You can see from the log that the failure did take a long time to show up. About 75hrs.
I saw a reference similar here: #5023
But it led to stale.
My router is a TPLink AC1750
Debug Logs
I (184827287) wifi:state: run -> init (6c0)
I (184827297) wifi:pm stop, total sleep time: 101950385411 us / 120855147958 us
I (184827297) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184827307) SOUND: Send sound queue: 146-1�[0m
�[0;32mI (184827347) WIFI: Disconnected from wifi:6�[0m
�[0;32mI (184827347) SOUND: Playing: /spiffs/wifi_disconnected.mp3�[0m
�[0;32mI (184827347) WIFI: connection_retry: 1�[0m
�[0;32mI (184827397) WIFI: MQTT task stopping...�[0m
I (184828477) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184828477) wifi:state: init -> auth (b0)
I (184828487) wifi:state: auth -> assoc (0)
I (184828497) wifi:state: assoc -> run (10)
I (184828497) wifi:state: run -> init (ea0)
I (184828497) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184828497) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184828517) WIFI: Disconnected from wifi:14�[0m
�[0;32mI (184828517) WIFI: connection_retry: 2�[0m
�[0;32mI (184828787) SOUND: Finished: /spiffs/wifi_disconnected.mp3�[0m
�[0;32mI (184831577) WIFI: Disconnected from wifi:205�[0m
�[0;32mI (184831577) WIFI: connection_retry: 3�[0m
I (184832697) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184832697) wifi:state: init -> auth (b0)
I (184832707) wifi:state: auth -> assoc (0)
I (184832707) wifi:state: assoc -> run (10)
I (184832717) wifi:state: run -> init (ea0)
I (184832717) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184832717) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184832727) WIFI: Disconnected from wifi:14�[0m
�[0;32mI (184832727) WIFI: connection_retry: 4�[0m
�[0;32mI (184835787) WIFI: Disconnected from wifi:205�[0m
�[0;32mI (184835787) WIFI: connection_retry: 5�[0m
I (184836907) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184836907) wifi:state: init -> auth (b0)
I (184836907) wifi:state: auth -> assoc (0)
I (184836917) wifi:state: assoc -> run (10)
I (184836917) wifi:state: run -> init (ea0)
I (184836917) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184836927) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184836937) WIFI: Disconnected from wifi:14�[0m
�[0;32mI (184836937) WIFI: connection_retry: 6�[0m
�[0;32mI (184839997) WIFI: Disconnected from wifi:205�[0m
�[0;32mI (184839997) WIFI: connection_retry: 7�[0m
I (184841117) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184841117) wifi:state: init -> auth (b0)
I (184841127) wifi:state: auth -> assoc (0)
I (184841147) wifi:state: assoc -> run (10)
I (184841147) wifi:state: run -> init (ea0)
I (184841147) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184841147) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184841157) WIFI: Disconnected from wifi:14�[0m
�[0;32mI (184841157) WIFI: connection_retry: 8�[0m
�[0;32mI (184844217) WIFI: Disconnected from wifi:205�[0m
�[0;32mI (184844217) WIFI: connection_retry: 9�[0m
I (184845337) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184845337) wifi:state: init -> auth (b0)
I (184845347) wifi:state: auth -> assoc (0)
I (184845357) wifi:state: assoc -> run (10)
I (184845357) wifi:state: run -> init (ea0)
I (184845357) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184845367) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184845377) WIFI: Disconnected from wifi:14�[0m
�[0;32mI (184845377) WIFI: connection_retry: 10�[0m
�[0;32mI (184848437) WIFI: Disconnected from wifi:205�[0m
�[0;32mI (184848437) WIFI: connection_retry: 11�[0m
�[0;32mI (184848437) WIFI: Scanning for wifi networks...�[0m
�[0;32mI (184850557) WIFI: Scan Done�[0m
�[0;32mI (184850557) WIFI: RAM left 4015652�[0m
�[0;32mI (184850557) WIFI: provisioned: 1�[0m
�[0;32mI (184850557) WIFI: SSID 0:Azena Guest�[0m
�[0;32mI (184850567) WIFI: SSID 1:Azena F�[0m
�[0;32mI (184850567) WIFI: Attempting to connect to wifi Azena F�[0m
�[0;32mI (184850577) WIFI: SSID 2:DIRECT-C5-HP OfficeJet Pro 8710�[0m
�[0;32mI (184850577) WIFI: SSID 3:PFF-2.4G�[0m
�[0;32mI (184850587) WIFI: SSID 4:BridgeWC�[0m
�[0;32mI (184850587) WIFI: SSID 5:GORDON REESE DESIGN BUILD�[0m
�[0;32mI (184850587) WIFI: SSID 6:GORDON REESE guest�[0m
�[0;32mI (184850597) WIFI: SSID 7:PFF-2.4G_RPT�[0m
�[0;32mI (184850597) WIFI: SSID 8:DIRECT-ba-HP M277 LaserJet�[0m
�[0;32mI (184850617) WIFI: SSID 9:PAD5�[0m
�[0;32mI (184850617) WIFI: SSID 10:DIRECT-3e-HP M118 LaserJet�[0m
�[0;32mI (184850617) WIFI: SSID 11:Pocklingtonlaw�[0m
�[0;32mI (184850627) WIFI: SSID 12:evanjuliet-2.4�[0m
�[0;32mI (184850627) WIFI: SSID 13:VAAK LLP�[0m
�[0;32mI (184850627) WIFI: SSID 14:DIRECT-64-HP OfficeJet Pro 8710�[0m
�[0;32mI (184850637) WIFI: SSID 15:Cappo-2.4�[0m
�[0;32mI (184850637) WIFI: SSID 16:Ericsson2.4G-2-1�[0m
�[0;32mI (184850647) WIFI: SSID 17:Citrus 2.4�[0m
�[0;32mI (184850647) WIFI: SSID 18:DIRECT-bb-HP M183 LaserJet�[0m
�[0;32mI (184850657) WIFI: SSID 19:ThomasWifi�[0m
�[0;32mI (184850667) WIFI: SSID 20:HannonLaw�[0m
�[0;32mI (184850667) WIFI: SSID 21:Linksys08645-guest�[0m
I (184850697) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184850697) wifi:state: init -> auth (b0)
I (184850707) wifi:state: auth -> assoc (0)
I (184850717) wifi:state: assoc -> run (10)
I (184850717) wifi:state: run -> init (ea0)
I (184850717) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
I (184850717) wifi:new:<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1
�[0;32mI (184850737) WIFI: Disconnected from wifi:14�[0m
The text was updated successfully, but these errors were encountered: