esp-idf: Wifi disconnects and is unable to reconnect with WIFI_REASON_MIC_FAILURE code (IDFGH-5142)

Environment

  • Module or chip used: ESP32-WROVER-E
  • IDF version (run git describe --tags to find it): v4.2
  • Build System: idf.py
  • Compiler version (run xtensa-esp32-elf-gcc --version to find it): xtensa-esp32-elf-gcc (crosstool-NG esp-2020r3) 8.4.0
  • Operating System: Windows
  • (Windows only) environment type: VSCode.
  • Using an IDE?: VSCode]
  • Power Supply: external 3.3V

Problem 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: https://github.com/espressif/esp-idf/issues/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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184827307) SOUND: Send sound queue: 146-1 I (184827347) WIFI: Disconnected from wifi:6 I (184827347) SOUND: Playing: /spiffs/wifi_disconnected.mp3 I (184827347) WIFI: connection_retry: 1 I (184827397) WIFI: MQTT task stopping… I (184828477) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184828497) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184828517) WIFI: Disconnected from wifi:14 I (184828517) WIFI: connection_retry: 2 I (184828787) SOUND: Finished: /spiffs/wifi_disconnected.mp3 I (184831577) WIFI: Disconnected from wifi:205 I (184831577) WIFI: connection_retry: 3 I (184832697) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184832717) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184832727) WIFI: Disconnected from wifi:14 I (184832727) WIFI: connection_retry: 4 I (184835787) WIFI: Disconnected from wifi:205 I (184835787) WIFI: connection_retry: 5 I (184836907) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184836927) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184836937) WIFI: Disconnected from wifi:14 I (184836937) WIFI: connection_retry: 6 I (184839997) WIFI: Disconnected from wifi:205 I (184839997) WIFI: connection_retry: 7 I (184841117) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184841147) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184841157) WIFI: Disconnected from wifi:14 I (184841157) WIFI: connection_retry: 8 I (184844217) WIFI: Disconnected from wifi:205 I (184844217) WIFI: connection_retry: 9 I (184845337) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184845367) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184845377) WIFI: Disconnected from wifi:14 I (184845377) WIFI: connection_retry: 10 I (184848437) WIFI: Disconnected from wifi:205 I (184848437) WIFI: connection_retry: 11 I (184848437) WIFI: Scanning for wifi networks… I (184850557) WIFI: Scan Done I (184850557) WIFI: RAM left 4015652 I (184850557) WIFI: provisioned: 1 I (184850557) WIFI: SSID 0:Azena Guest I (184850567) WIFI: SSID 1:Azena F I (184850567) WIFI: Attempting to connect to wifi Azena F I (184850577) WIFI: SSID 2:DIRECT-C5-HP OfficeJet Pro 8710 I (184850577) WIFI: SSID 3:PFF-2.4G I (184850587) WIFI: SSID 4:BridgeWC I (184850587) WIFI: SSID 5:GORDON REESE DESIGN BUILD I (184850587) WIFI: SSID 6:GORDON REESE guest I (184850597) WIFI: SSID 7:PFF-2.4G_RPT I (184850597) WIFI: SSID 8:DIRECT-ba-HP M277 LaserJet I (184850617) WIFI: SSID 9:PAD5 I (184850617) WIFI: SSID 10:DIRECT-3e-HP M118 LaserJet I (184850617) WIFI: SSID 11:Pocklingtonlaw I (184850627) WIFI: SSID 12:evanjuliet-2.4 I (184850627) WIFI: SSID 13:VAAK LLP I (184850627) WIFI: SSID 14:DIRECT-64-HP OfficeJet Pro 8710 I (184850637) WIFI: SSID 15:Cappo-2.4 I (184850637) WIFI: SSID 16:Ericsson2.4G-2-1 I (184850647) WIFI: SSID 17:Citrus 2.4 I (184850647) WIFI: SSID 18:DIRECT-bb-HP M183 LaserJet I (184850657) WIFI: SSID 19:ThomasWifi I (184850667) WIFI: SSID 20:HannonLaw I (184850667) WIFI: SSID 21:Linksys08645-guest I (184850697) wifi🆕<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🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184850717) wifi🆕<2,0>, old:<2,0>, ap:<255,255>, sta:<2,0>, prof:1 I (184850737) WIFI: Disconnected from wifi:14

About this issue

  • Original URL
  • State: open
  • Created 3 years ago
  • Comments: 47 (18 by maintainers)

Most upvoted comments

hi, @Pabs84, you can send it to the following email sales@espressif.com 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 @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.

@jack0c @mbratch I found out that disabling WiFi Multimedia Management (WMM) in my Router solved the issue for all my esp32 and esp8266. But this limits the Bandwith of my 2.4GHz WiFi to 54mbit/s. So there seems to be a problem with the esp-idf implementation of WMM. With older routers i did not encouter the disconnecting issue at all. Is it possible to disable WMM in your Airport Extreme to verify my results?

My mistake… I had forgotten I set info on my code. Here it is a successful log and I’ll post another when it fails: `D (12058) wifi:clear blacklist I (12058) WIFI: Attempting to connect to wifi Azena F D (12058) wifi:Start wifi connect D (12068) wifi:connect status 0 -> 0 D (12068) wifi:connect chan=0 D (12068) wifi:first chan=1 D (12068) wifi:connect status 0 -> 1 D (12078) wifi:filter: set rx policy=3 D (12078) wifi:clear scan ap list D (12078) wifi:start scan: type=0x50f, priority=2, cb=0x401b2b04, arg=0x0, ss_state=0x1, time=2535293, index=0 0x401b2b04: cnx_start_handoff_cb at ??:?

D (12088) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120> I (12098) WIFI: SSID 1:Azena Guest I (12098) WIFI: SSID 2:DIRECT-C5-HP OfficeJet Pro 8710 I (12108) WIFI: SSID 3:PFF-2.4G I (12108) WIFI: SSID 4:PFF-2.4G_RPT I (12118) WIFI: SSID 5:GORDON REESE guest I (12118) WIFI: SSID 6:GORDON REESE DESIGN BUILD I (12118) WIFI: SSID 7:BridgeWC I (12128) WIFI: SSID 8:GronowskiLaw I (12138) WIFI: SSID 9:DIRECT-3e-HP M118 LaserJet I (12138) WIFI: SSID 10:DIRECT-ba-HP M277 LaserJet I (12148) WIFI: SSID 11:Cappo-2.4 I (12148) WIFI: SSID 12:Citrus 2.4 I (12148) WIFI: SSID 13:PAD5 I (12158) WIFI: SSID 14:PAD2 I (12158) WIFI: SSID 15:JohnsonLaw I (12158) WIFI: SSID 16:CBCI-748D-2.4 I (12168) WIFI: SSID 17:VAAK LLP I (12168) WIFI: SSID 18:ThomasWifi I (12168) WIFI: SSID 19:WTP-Guest I (12188) WIFI: SSID 20:TP-LINK_2.4GHz_6E5BB5 D (12218) wifi:scan end: arg=0x0, status=0, ss_state=0x3 D (12218) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120> D (12218) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (12218) wifi:profile match: ss_state=0x7 D (12238) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (12238) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0> D (12238) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144 D (12248) wifi:profile match: ss_state=0x7 D (12248) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (12258) wifi:profile match: ss_state=0x7 D (12318) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (12318) wifi:profile match: ss_state=0x7 D (12338) wifi:scan end: arg=0x0, status=0, ss_state=0x7 D (12338) wifi:find first mathched ssid, scan done D (12338) wifi:filter: set rx policy=4 D (12338) wifi:first chan=1 D (12348) wifi:handoff_cb: status=0 D (12348) wifi:ap found, mac=cc:32:e5:4a:72:45 D (12358) wifi:new_bss=0x3ffc6cb8, cur_bss=0x0, new_chan=<2,0>, cur_chan=1 D (12368) wifi:filter: set rx policy=5 I (12368) wifi🆕<2,0>, old:<1,0>, ap:<255,255>, sta:<2,0>, prof:1 D (12378) wifi:connect_op: status=0, auth=5, cipher=3 D (12378) wifi:auth mode is not none D (12768) wifi:connect_bss: auth=1, reconnect=0 I (12768) wifi:state: init -> auth (b0) D (12768) wifi:start 1s AUTH timer D (12768) wifi:clear scan ap list D (12768) 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 (12788) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

D (12798) wifi:recv auth: seq=2, status=0 I (12808) wifi:state: auth -> assoc (0) D (12808) wifi:restart connect 1s timer for assoc D (12808) wifi:recv assoc: type=0x10 D (12808) wifi:filter: set rx policy=6 I (12808) wifi:state: assoc -> run (10) D (12828) wifi:start 10s connect timer for 4 way handshake D (12828) wpa: IEEE 802.1X RX: version=2 type=3 length=95

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 (12848) wpa: 02 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 D (12848) wpa: 01 44 5f c3 85 fc 74 1c 05 d9 a1 be 0f 96 12 24 D (12858) wpa: fe 2e 66 b4 b1 ea 5d 0f 0c c9 73 f5 13 8e 82 66 D (12868) wpa: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (12878) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (12878) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (12888) wpa: 00 00 00 D (12888) wpa: WPA 1/4-Way Handshake

D (12888) wpa: RSN: msg 1/4 key data - hexdump(len=0): D (12898) wpa: WPA: PTK derivation - A1=fc:f5:c4:3c:f0:04 A2=cc:32:e5:4a:72:45

D (12898) wpa: WPA: PMK - hexdump(len=32): D (12908) wpa: d8 02 56 70 60 84 35 25 48 77 cd 74 83 36 43 35 D (12918) wpa: 12 b4 37 21 34 d3 1b 90 2b 43 8f f8 05 62 6e 22 D (12928) wpa: WPA: PTK - hexdump(len=48): D (12928) wpa: c7 1a 01 ef 74 b7 5e c6 1b ef 34 bf e5 9a 1f c5 D (12928) wpa: 3e fa 16 fa 3b 19 ae 1f 74 b9 46 6c 1c a6 45 88 D (12938) wpa: 43 45 0d 09 ef 6e 2b 1f bd af d4 cf 2d 8c e2 f4 D (12938) wpa: WPA: WPA IE for msg 2/4

  • hexdump(len=22): D (12948) wpa: 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 D (12948) wpa: 00 0f ac 02 00 00 D (12958) wpa: WPA Send EAPOL-Key 2/4

D (12958) wpa: WPA: TX EAPOL-Key - hexdump(len=121): D (12958) wpa: 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 D (12978) wpa: 01 07 1b 5f 6b 42 e5 65 37 45 57 27 56 db a9 0d D (12978) wpa: fd 33 11 8e 16 8a 21 cf c3 00 6b 43 b5 bc cb 54 D (12988) wpa: 5b 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (12988) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (12998) wpa: 00 47 bd 66 ff 79 62 1f 90 d5 7e 23 71 65 97 22 D (12998) wpa: 09 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac D (13008) wpa: 04 01 00 00 0f ac 02 00 00 D (13018) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

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 (13058) wpa: 02 03 00 c7 02 13 ca 00 10 00 00 00 00 00 00 00 D (13058) wpa: 02 44 5f c3 85 fc 74 1c 05 d9 a1 be 0f 96 12 24 D (13068) wpa: fe 2e 66 b4 b1 ea 5d 0f 0c c9 73 f5 13 8e 82 66 D (13068) wpa: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (13078) wpa: 00 dc 96 01 00 00 00 00 00 00 00 00 00 00 00 00 D (13078) wpa: 00 90 80 74 d3 89 27 e4 ce fb d2 c0 8e 23 99 fe D (13098) wpa: d9 00 68 13 ce 61 84 ab 20 e6 3b 9a 13 ef 83 93 D (13098) wpa: b6 4a a9 41 09 4d 95 1f 96 09 97 d0 0c dd c6 76 D (13108) wpa: 78 0a 55 a4 73 77 51 ed 6a f6 68 2e 24 9d bf e6 D (13108) wpa: 8e f8 15 3a 65 fa 9a 01 41 5a d1 37 ae 10 b3 ca D (13118) wpa: 3a 26 49 89 bc 60 e8 d2 fa d9 c2 3d 82 83 5d 32 D (13118) wpa: e0 b5 00 5e fd 21 13 46 9c 74 4a ca 54 9b 8a 13 D (13128) wpa: a3 4f d5 87 15 38 cf 83 ff 4d 3d D (13128) wpa: WPA 3/4-Way Handshake

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 (13158) wpa: 01 03 00 5f 02 03 0a 00 00 00 00 00 00 00 00 00 D (13168) wpa: 02 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (13168) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (13178) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (13178) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 D (13198) wpa: 00 3b 29 b7 8f c9 63 87 10 5a 36 f0 d2 17 43 45 D (13198) wpa: df 00 00 D (13198) wifi:rsn valid: gcipher=1 ucipher=3 akm=5

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 I (13238) wifi:security: WPA2-PSK, phy: bgn, rssi: -42 D (13238) wifi:remove all except cc:32:e5:4a:72:45 from rc list D (13248) wifi:clear blacklist D (13248) wifi:filter: set rx policy=7 I (13248) wifi:pm start, type: 1

D (13248) wifi:Send sta connected event D (13268) wifi:connect status 1 -> 5 D (13268) wifi:obss scan is disabled D (13268) wifi:start obss scan: obss scan is stopped I (13278) wifi:AP’s beacon interval = 102400 us, DTIM period = 1 D (13268) event: running post WIFI_EVENT:4 with handler 0x4015a588 and context 0x3ffe1e38 on loop 0x3ffdcfc8 0x4015a588: wifi_default_action_sta_connected at C:/esp/esp-idf/components/esp_wifi/src/wifi_default.c:88

D (13288) esp_netif_handlers: esp_netif action connected with netif0x3ffe15e4 from event_id=4 D (13288) esp_netif_lwip: check: remote, if=0x3ffe15e4 fn=0x40152544 0x40152544: esp_netif_up_api at C:/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1131

D (13308) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffe15e4 D (13308) esp_netif_lwip: check: local, if=0x3ffe15e4 fn=0x40152d78 0x40152d78: esp_netif_update_default_netif_lwip at C:/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163

D (13318) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffe15e4 D (13328) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (13328) esp_netif_lwip: check: remote, if=0x3ffe15e4 fn=0x40152104 0x40152104: esp_netif_dhcpc_start_api at C:/esp/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:929

D (13328) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffe15e4 D (13338) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffe15e4 D (13358) esp_netif_lwip: if0x3ffe15e4 start ip lost tmr: no need start because netif=0x3ffe1668 interval=120 ip=0 D (13358) esp_netif_lwip: starting dhcp client D (13368) esp_netif_lwip: call api in lwip: ret=0x0, give sem D (13368) event: running post WIFI_EVENT:4 with handler 0x400e77a8 and context 0x3ffe3cc4 on loop 0x3ffdcfc8 0x400e77a8: event_handler at c:\users\owner\dropbox\azena\glass2\esp32\azena_glass2_production\build/…/main/wifi.c:134

I (13378) WIFI: Connected to wifi network Azena F D (14168) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3ffe1668 D (14168) esp_netif_lwip: if0x3ffe15e4 ip changed=1 D (14168) event: running post IP_EVENT:0 with handler 0x4015a3a4 and context 0x3ffe1eec on loop 0x3ffdcfc8 0x4015a3a4: wifi_default_action_sta_got_ip at C:/esp/esp-idf/components/esp_wifi/src/wifi_default.c:128

D (14178) wifi_init_default: Got IP wifi default handler entered D (14188) esp_netif_handlers: esp_netif action got_ip with netif0x3ffe15e4 from event_id=0 I (14188) esp_netif_handlers: sta ip: 192.168.0.214, mask: 255.255.255.0, gw: 192.168.0.1 D (14208) event: running post IP_EVENT:0 with handler 0x400e77a8 and context 0x3ffe3cdc on loop 0x3ffdcfc8 0x400e77a8: event_handler at c:\users\owner\dropbox\azena\glass2\esp32\azena_glass2_production\build/…/main/wifi.c:134`