esp-idf: DPP Auth Failed on dpp-enrollee example (IDFGH-9228)

Answers checklist.

  • I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
  • I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
  • I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v4.4.3

Operating System used.

Windows

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

PowerShell

Development Kit.

ESP32-WROVER-DevkitC

Power Supply used.

USB

What is the expected behavior?

I expected it to correctly authenticate with Accesspoint.

What is the actual behavior?

It does not authenticate with accesspoint at all; Seems that it fails with WPA being D (66148) wpa: Mgmt Tx Status - 1, Cookie - 0x400e036c, and returns ESP_ERR_DPP_TX_FAILURE no matter what accesspoint it uses.

Steps to reproduce.

Code It is 1:1 to the example, expect I removed the key part. which should just work without it.

Debug Logs.

D (64538) wpa: DPP: Rx Public Action frame: action - 9
I (64538) wpa: DPP: Authentication Request from ac:3e:b1:02:80:e0
D (64538) event: running post WIFI_EVENT:20 with handler 0x400d6adc and context 0x3ffbdcfc on loop 0x3ffbc9f0
0x400d6adc: event_handler(void*, char const*, int, void*) at C:/Users/Alma/sensor-data-update/main/main.cpp:55

E (64548) wpa: curve: secp256r1

E (64558) wpa: prime len is 32

E (64558) wpa: Q_x: - hexdump(len=32):
E (64568) wpa: 2e cc 68 18 67 c2 7a 7f d2 59 20 1f 89 c5 99 28
E (64568) wpa: d2 59 3b 12 b9 07 13 4d 04 02 9a 80 0e 57 69 5c
E (64578) wpa: Q_y: - hexdump(len=32):
E (64578) wpa: 52 00 62 4e d9 33 98 b6 79 86 f6 ba 1c 20 a0 34
E (64588) wpa: 6f ec 12 e8 8d 28 56 47 7e 6b 09 00 48 04 84 29 
E (64598) wpa: d:      - hexdump(len=32):
E (64598) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
E (64608) wpa: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
D (64558) event: running post WIFI_EVENT:20 with handler 0x400e0420 and context 0x3ffcf050 on loop 0x3ffbc9f0
0x400e0420: offchan_event_handler at C:/Users/Alma/esp443/esp-idf/components/wpa_supplicant/esp_supplicant/src/esp_dpp.c:449

D (64858) wpa: DPP: ECDH shared secret (M.x) - hexdump(len=32):
D (64858) wpa: f0 8c 6a ab fc 7b b8 4e 1b 6f f0 ff b7 2d a7 51
D (64858) wpa: 0a 20 b7 ac ae e7 de 04 58 42 a2 fd 44 22 44 9c 
D (64868) wpa: DPP: PRK = HKDF-Extract(<>, IKM=M.x) - hexdump(len=32):
D (64878) wpa: bc 82 9b f7 0b 3d 4d 33 4a 14 1f 11 9d d0 76 ff
D (64878) wpa: 76 f6 99 be c7 1f 2e 87 b2 8d d7 11 4f e5 ce 4f 
D (64888) wpa: DPP: k1 = HKDF-Expand(PRK, info, L) - hexdump(len=32):
D (64888) wpa: 0a e1 3c 28 f3 44 cf 2d 60 c0 f1 75 63 9d 19 4a
D (64898) wpa: 55 49 3f 69 61 4f 8a f0 68 22 7d ab 9e 0e 11 48 
D (64908) wpa: DDP: AES-SIV AD[0] - hexdump(len=6):
D (64908) wpa: 50 6f 9a 1a 01 00
D (64908) wpa: DDP: AES-SIV AD[1] - hexdump(len=145):
D (64918) wpa: 02 10 20 00 d1 29 db 70 63 65 7c e0 a6 69 1d 0e
D (64928) wpa: 7b b4 2e c4 dc b0 9b f1 70 94 43 b4 45 44 d9 d5
D (64928) wpa: c2 50 90 a7 01 10 20 00 ad 99 e9 8c 5d c3 e0 73 
D (64938) wpa: 5f 15 68 77 32 88 6c 42 64 18 88 a2 eb 22 85 52
D (64938) wpa: f3 15 f7 d4 16 d7 21 f7 03 10 40 00 2e cc 68 18 
D (64948) wpa: 67 c2 7a 7f d2 59 20 1f 89 c5 99 28 d2 59 3b 12
D (64958) wpa: b9 07 13 4d 04 02 9a 80 0e 57 69 5c 52 00 62 4e
D (64958) wpa: d9 33 98 b6 79 86 f6 ba 1c 20 a0 34 6f ec 12 e8 
D (64968) wpa: 8d 28 56 47 7e 6b 09 00 48 04 84 29 19 10 01 00
D (64968) wpa: 02
D (64978) wpa: DPP: AES-SIV ciphertext - hexdump(len=41):
D (64978) wpa: 5e 3c b5 ca a8 35 62 48 31 16 73 3f 86 1b 05 fd
D (64988) wpa: ca ee a0 d1 f2 ec c4 c2 a1 be f9 d3 f1 a5 f8 21
D (64988) wpa: 2d 76 12 f0 68 d6 36 44 b2 
D (64998) wpa: DPP: AES-SIV cleartext - hexdump(len=25):
D (64998) wpa: 05 10 10 00 0c fc 37 2f 56 14 8d 2e 3d e5 34 6b
D (65008) wpa: 74 4e 2e f9 06 10 01 00 02 
D (65008) wpa: DPP: I-nonce - hexdump(len=16):
D (65018) wpa: 0c fc 37 2f 56 14 8d 2e 3d e5 34 6b 74 4e 2e f9
D (65018) wpa: DPP: I-capabilities: 0x02
D (65028) wpa: DPP: Acting as Enrollee
D (65028) wpa: DPP: Build Authentication Response
D (65038) wpa: DPP: R-nonce - hexdump(len=16):
D (65038) wpa: f3 e7 c0 99 c3 ce 25 58 c4 e3 96 ab a0 47 3c f8
D (65288) wpa: DPP: Generating a keypair
E (65288) wpa: curve: secp256r1

E (65288) wpa: prime len is 32

E (65288) wpa: Q_x: - hexdump(len=32):
E (65298) wpa: 27 57 28 28 50 5c 1a a0 32 d2 b2 ba ac c4 24 9b
E (65298) wpa: f1 e5 87 a5 07 5c 3f 90 ce 43 6e 8a 89 eb eb 49 
E (65308) wpa: Q_y: - hexdump(len=32):
E (65308) wpa: 2b c3 e2 49 c8 08 4a 73 d1 ad f4 4d 90 54 40 6c
E (65318) wpa: 2f a1 32 50 a1 9e de 32 0a 11 c4 ed 61 9f 56 25 
E (65328) wpa: d:      - hexdump(len=32):
E (65328) wpa: c1 ec c8 73 ad 41 bf 26 37 2a a9 bf e5 9a d5 06 
E (65338) wpa: c1 f2 d3 81 0e 79 3c 8b dc d6 92 50 bd 1e 27 05
D (65588) wpa: DPP: ECDH shared secret (N.x) - hexdump(len=32):
D (65588) wpa: be 3d 4a 7a eb 32 19 3b 94 6a f7 70 66 d8 0c dc
D (65588) wpa: bc 32 0a 6f de 6f 70 4c 21 7b 6c 0f 42 2e 20 e8
D (65598) wpa: DPP: PRK = HKDF-Extract(<>, IKM=N.x) - hexdump(len=32):
D (65608) wpa: 4d 13 bb a1 f2 0a 4c 8d 51 0c 6c e1 7d cb f0 2c
D (65608) wpa: 65 b8 1e 4f 2c 67 06 46 bf b2 a5 0e e5 40 6f 27
D (65618) wpa: DPP: k2 = HKDF-Expand(PRK, info, L) - hexdump(len=32):
D (65618) wpa: ea 9f 7b 91 4c 0d d2 65 71 a5 29 9f a3 1f 05 ee
D (65628) wpa: 46 97 50 c3 18 32 1c 3d 1d 46 f7 d1 0f dd ef 76
D (65638) wpa: DPP: PRK = HKDF-Extract(<>, IKM) - hexdump(len=32):
D (65638) wpa: bb 7e e1 47 48 0f 02 d3 bc 1d 71 90 b8 cd 9d 73 
D (65648) wpa: b9 b1 3f 2a 34 cb 8a 67 f5 ae 43 ff f0 86 b0 7c
D (65648) wpa: DPP: ke = HKDF-Expand(PRK, info, L) - hexdump(len=32):
D (65658) wpa: ff d7 30 d0 7c 67 c5 a3 c3 bc da c9 f8 2a 6e 72 
D (65668) wpa: 16 76 98 2b d7 c7 1e bd 08 17 08 cb d9 9d 7a d5
D (65668) wpa: DPP: R-auth hash components
D (65678) wpa: DPP: hash component - hexdump(len=16):
D (65678) wpa: 0c fc 37 2f 56 14 8d 2e 3d e5 34 6b 74 4e 2e f9
D (65688) wpa: DPP: hash component - hexdump(len=16):
D (65688) wpa: f3 e7 c0 99 c3 ce 25 58 c4 e3 96 ab a0 47 3c f8 
D (65698) wpa: DPP: hash component - hexdump(len=32):
D (65698) wpa: 2e cc 68 18 67 c2 7a 7f d2 59 20 1f 89 c5 99 28 
D (65708) wpa: d2 59 3b 12 b9 07 13 4d 04 02 9a 80 0e 57 69 5c
D (65718) wpa: DPP: hash component - hexdump(len=32):
D (65718) wpa: 27 57 28 28 50 5c 1a a0 32 d2 b2 ba ac c4 24 9b 
D (65728) wpa: f1 e5 87 a5 07 5c 3f 90 ce 43 6e 8a 89 eb eb 49
D (65728) wpa: DPP: hash component - hexdump(len=32):
D (65738) wpa: c2 3f 6d 38 b9 ec 86 c0 75 d5 78 35 81 61 c4 1e 
D (65738) wpa: 5f 23 d3 3a a0 4d a1 fc 62 64 ce e5 ed a6 dc c3
D (65748) wpa: DPP: hash component - hexdump(len=1):
D (65758) wpa: 00
D (65758) wpa: DPP: R-auth - hexdump(len=32):
D (65758) wpa: 9c 68 7a de 49 3a fe 3d d4 e9 25 80 32 19 3b fe
D (65768) wpa: 43 2c 6c c1 ef c7 ae f2 c4 d6 eb 56 a0 e2 12 c2
D (65768) wpa: DPP: {R-auth}ke - hexdump(len=52):
D (65778) wpa: b6 59 c0 88 77 cc bf f5 4a 17 84 e6 56 44 cc f2
D (65778) wpa: 5c f9 89 67 ef 97 6e 43 94 a4 bb f4 46 2c a4 8b
D (65788) wpa: e2 4c 9c 5d 1c cd 0f 97 ae 80 d8 16 4e 3d ac 09
D (65798) wpa: 59 e9 4b 2e
D (65798) wpa: DPP: Status 0
D (65798) wpa: DPP: R-Bootstrap Key Hash
D (65808) wpa: DDP: AES-SIV AD[0] - hexdump(len=6):
D (65808) wpa: 50 6f 9a 1a 01 01
D (65808) wpa: DDP: AES-SIV AD[1] - hexdump(len=109):
D (65818) wpa: 00 10 01 00 00 02 10 20 00 d1 29 db 70 63 65 7c
D (65828) wpa: e0 a6 69 1d 0e 7b b4 2e c4 dc b0 9b f1 70 94 43
D (65828) wpa: b4 45 44 d9 d5 c2 50 90 a7 09 10 40 00 27 57 28 
D (65838) wpa: 28 50 5c 1a a0 32 d2 b2 ba ac c4 24 9b f1 e5 87
D (65838) wpa: a5 07 5c 3f 90 ce 43 6e 8a 89 eb eb 49 2b c3 e2
D (65848) wpa: 49 c8 08 4a 73 d1 ad f4 4d 90 54 40 6c 2f a1 32 
D (65858) wpa: 50 a1 9e de 32 0a 11 c4 ed 61 9f 56 25
D (65858) wpa: DPP: AES-SIV cleartext - hexdump(len=101):
D (65868) wpa: 07 10 10 00 f3 e7 c0 99 c3 ce 25 58 c4 e3 96 ab
D (65868) wpa: a0 47 3c f8 05 10 10 00 0c fc 37 2f 56 14 8d 2e
D (65878) wpa: 3d e5 34 6b 74 4e 2e f9 08 10 01 00 01 04 10 34 
D (65878) wpa: 00 b6 59 c0 88 77 cc bf f5 4a 17 84 e6 56 44 cc
D (65888) wpa: f2 5c f9 89 67 ef 97 6e 43 94 a4 bb f4 46 2c a4
D (65898) wpa: 8b e2 4c 9c 5d 1c cd 0f 97 ae 80 d8 16 4e 3d ac 
D (65898) wpa: 09 59 e9 4b 2e
D (65908) wpa: DPP: AES-SIV ciphertext - hexdump(len=117):
D (65908) wpa: 67 1e e0 44 0e 3e df b0 13 64 39 c7 17 84 df ff 
D (65918) wpa: 5d 44 24 40 0a 8e e8 55 8b e5 41 33 d2 13 75 19
D (65918) wpa: 53 0a f3 91 1b 4d 06 97 c7 d4 ac 95 29 2d 4a da
D (65928) wpa: f8 e2 1b a7 f5 69 a5 2a 26 5b f9 8f 6a cd a1 18 
D (65938) wpa: 3b 6f 8b 4f ed e4 15 f8 25 b0 c9 35 7f c6 15 bb
D (65938) wpa: d2 77 dc b9 33 9b 5b 73 5b 8c 81 8e 96 45 c9 08 
D (65948) wpa: d6 39 7c 20 90 4c 70 14 06 87 41 e0 96 3d 9e b7
D (65948) wpa: 5a 9e b1 4e 7e
D (65958) wpa: DPP: Authentication Response frame attributes - hexdump(len=238):
D (65958) wpa: 04 09 50 6f 9a 1a 01 01 00 10 01 00 00 02 10 20
D (65968) wpa: 00 d1 29 db 70 63 65 7c e0 a6 69 1d 0e 7b b4 2e 
D (65978) wpa: c4 dc b0 9b f1 70 94 43 b4 45 44 d9 d5 c2 50 90
D (65978) wpa: a7 09 10 40 00 27 57 28 28 50 5c 1a a0 32 d2 b2
D (65988) wpa: ba ac c4 24 9b f1 e5 87 a5 07 5c 3f 90 ce 43 6e
D (65988) wpa: 8a 89 eb eb 49 2b c3 e2 49 c8 08 4a 73 d1 ad f4
D (65998) wpa: 4d 90 54 40 6c 2f a1 32 50 a1 9e de 32 0a 11 c4
D (66008) wpa: ed 61 9f 56 25 04 10 75 00 67 1e e0 44 0e 3e df
D (66008) wpa: b0 13 64 39 c7 17 84 df ff 5d 44 24 40 0a 8e e8
D (66018) wpa: 55 8b e5 41 33 d2 13 75 19 53 0a f3 91 1b 4d 06
D (66018) wpa: 97 c7 d4 ac 95 29 2d 4a da f8 e2 1b a7 f5 69 a5
D (66028) wpa: 2a 26 5b f9 8f 6a cd a1 18 3b 6f 8b 4f ed e4 15
D (66038) wpa: f8 25 b0 c9 35 7f c6 15 bb d2 77 dc b9 33 9b 5b
D (66038) wpa: 73 5b 8c 81 8e 96 45 c9 08 d6 39 7c 20 90 4c 70
D (66048) wpa: 14 06 87 41 e0 96 3d 9e b7 5a 9e b1 4e 7e
D (66048) wpa: DPP: Mgmt Tx - MAC:ac:3e:b1:02:80:e0, Channel-6, WaitT-500        
D (66138) event: running post WIFI_EVENT:19 with handler 0x400d6adc and context 0x3ffbdcfc on loop 0x3ffbc9f0
0x400d6adc: event_handler(void*, char const*, int, void*) at C:/Users/Alma/sensor-data-update/main/main.cpp:55

D (66138) event: running post WIFI_EVENT:19 with handler 0x400e0420 and context 0x3ffcf020 on loop 0x3ffbc9f0
0x400e0420: offchan_event_handler at C:/Users/Alma/esp443/esp-idf/components/wpa_supplicant/esp_supplicant/src/esp_dpp.c:449

D (66148) wpa: Mgmt Tx Status - 1, Cookie - 0x400e036c
0x400e036c: esp_supp_rx_action at C:/Users/Alma/esp443/esp-idf/components/wpa_supplicant/esp_supplicant/src/esp_dpp.c:413

I (66148) wifi dpp-enrollee: DPP Auth failed (Reason: ESP_ERR_DPP_TX_FAILURE), retry...
D (66658) event: running post WIFI_EVENT:20 with handler 0x400d6adc and context 0x3ffbdcfc on loop 0x3ffbc9f0
0x400d6adc: event_handler(void*, char const*, int, void*) at C:/Users/Alma/sensor-data-update/main/main.cpp:55

D (66658) event: running post WIFI_EVENT:20 with handler 0x400e0420 and context 0x3ffcf050 on loop 0x3ffbc9f0
0x400e0420: offchan_event_handler at C:/Users/Alma/esp443/esp-idf/components/wpa_supplicant/esp_supplicant/src/esp_dpp.c:449

More Information.

Seems afterwards it crashes Wi-Fi module.

About this issue

  • Original URL
  • State: open
  • Created a year ago
  • Comments: 32 (17 by maintainers)

Commits related to this issue

Most upvoted comments

From my testing today, I’ve found that if the channel the esp is currently listening on happens to match whichever channel my phone was connected to AP on, the chance of ESP_ERR_DPP_TX_FAILURE dramatically drops and would happen rarely. This would explain the issue being intermittent and also not fixing itself for a while, since AP’s dont really change their channels too often, if at all. However that doesn’t get us very far since it means we need to somehow know the channel before we know what AP or anything. Which also doesn’t make sense since the phone already sends the first frame to the esp on the correct channel to begin with (channel 6 in the example), and then attempts to send it back to the phone on that same channel. From what I can tell, the issue comes from the call esp_wifi_action_tx_req on line 96 inside esp_send_action_frame Although the error isn’t immediately sent to the callback in the lines below and instead that callback is sent the error only when the WIFI_EVENT_ACTION_TX_STATUS wifi event is triggered on line 447 in offchan_event_handler

So from what I can tell, the issue comes down to just being purely a channel mismatch somehow and the esp not wanting to send to a different channel than its listening to(just a wild guess on that last part though).


And, it seems that there’s a fix that works perfectly(from my testing atleast), all it takes is enabling Multi Band Support in your sdkconfig. So essentially all you have to do is:

CONFIG_WPA_11KV_SUPPORT=y
CONFIG_WPA_SCAN_CACHE=y
CONFIG_WPA_MBO_SUPPORT=y
CONFIG_WPA_DPP_SUPPORT=y

Instead of only doing CONFIG_WPA_DPP_SUPPORT=y (11KV_SUPPORT and SCAN_CACHE are both required by MBO_SUPPORT)

This fix seems to work well enough that I can even have the esp listening only on channel 10, my phone can be sitting on channel 149, and I can get the esp to connect to a network on channel 1 with no issue I have no idea if this is meant to fix it, or if it’s going to break somewhere down the like, but nothing I can do can cause the ESP_ERR_DPP_TX_FAILURE as long as I have MBO Support enabled

I don’t know for sure, but it crashes Wi-Fi event handler hardly afterwards. I cannot receive any events after DPP had failed. I assume that might have to do with how LWIP is handling packets? (Or is it just my condition being bad…)

I see the same thing re the hard crash, but I don’t believe it is related to LWIP packet fragmentation. These aren’t even IP packets AFAICT, they’re action frame packets in 802.11. Further, I’m seeing essentially identical behavior to you with the unmodified example, which I’m guessing is the same thing our friends at Espressif are testing with but seeing different results. Highly likely an environmental condition causing the difference.

I don’t know for sure, but it crashes Wi-Fi event handler hardly afterwards. I cannot receive any events after DPP had failed. I assume that might have to do with how LWIP is handling packets? (Or is it just my condition being bad…)