WPA2 PEAP Connection Issue on SDK v3.4 (GIT8266O-723)

[SaurabhCoolR]

Environment

• Development Kit: NodeMCU 12E
• IDF version : release/v3.4
• Development Env: Make
• Operating System: Ubuntu 20.04
• Power Supply: USB

Problem Description

The WPA2 Enterprise Example Doesn't Work with SDK v3.4.

Due to inconsistency in PEAP Connection, We wanted to move our firmware based on ESP8266 RTOS SDK commit ID 655f934 (near release/v3.1.2) to SDK v3.4. But we observe that using SDK v3.4, the PEAP Connection becomes worse.

Expected Behavior

The PEAP Connection with SDK v3.4 is supposed to improve.

Actual Behavior

As we compared the PEAP connection by running the wpa2_enterprise example, it seems PEAP connection way worse with latest release v3.4. It's always giving Disconnect reason 23, 802.1x Auth Failed. This was not the issue when we tried the same example with commit ID 655f934.

Steps to reproduce

1. Clone the ESP8266 RTOS SDK on Ubuntu machine and set it up properly as given in documentation
2. Run the wpa2_enterprise example in examples/wifi by setting the PEAP Credentials in sdkconfig using menuconfig.
3. Comment out the part of code used for certification.
4. Tested on Node MCU ESP8266-12E Dev Kit plugged with USB to Ubuntu system.

Code to reproduce this issue

Just attaching the code for initialise_wifi function where I have commented the lines to set the cert bytes.

static void initialise_wifi(void)
{
    unsigned int ca_pem_bytes = ca_pem_end - ca_pem_start;
    unsigned int client_crt_bytes = client_crt_end - client_crt_start;
    unsigned int client_key_bytes = client_key_end - client_key_start;

    tcpip_adapter_init();
    wifi_event_group = xEventGroupCreate();
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK(esp_wifi_init(&cfg));
    ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &event_handler, NULL));
    ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, IP_EVENT_STA_GOT_IP, &event_handler, NULL));
    ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_RAM));
    wifi_config_t wifi_config = {
        .sta = {
            .ssid = EXAMPLE_WIFI_SSID,
        },
    };
    ESP_LOGI(TAG, "Setting WiFi configuration SSID %s...", wifi_config.sta.ssid);
    ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_STA));
    ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_STA, &wifi_config));
    // ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_set_ca_cert(ca_pem_start, ca_pem_bytes));
    // ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_set_cert_key(client_crt_start, client_crt_bytes,
                    // client_key_start, client_key_bytes, NULL, 0));
    ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_set_identity((uint8_t*)EXAMPLE_EAP_ID, strlen(EXAMPLE_EAP_ID)));

    if (EXAMPLE_EAP_METHOD == EAP_PEAP || EXAMPLE_EAP_METHOD == EAP_TTLS) {
        ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_set_username((uint8_t*)EXAMPLE_EAP_USERNAME, strlen(EXAMPLE_EAP_USERNAME)));
        ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_set_password((uint8_t*)EXAMPLE_EAP_PASSWORD, strlen(EXAMPLE_EAP_PASSWORD)));
    }

    ESP_ERROR_CHECK(esp_wifi_sta_wpa2_ent_enable());
    ESP_ERROR_CHECK(esp_wifi_start());
}

Following is the PEAP Config details in SDK Config:

CONFIG_WIFI_SSID="TP-Link_2BAB"
CONFIG_EAP_METHOD=1
CONFIG_EAP_ID="Test@TEST.LOCAL"
CONFIG_EAP_USERNAME="Test@TEST.LOCAL"
CONFIG_EAP_PASSWORD="spraxa@2021"

Debug Logs

I (49) boot: ESP-IDF v3.4-39-g23a225a5-dirty 2nd stage bootloader
I (50) boot: compile time 19:26:58
I (50) boot: SPI Speed      : 80MHz
I (54) boot: SPI Mode       : DOUT
I (58) boot: SPI Flash Size : 4MB
I (62) boot: Partition Table:
I (66) boot: ## Label            Usage          Type ST Offset   Length
I (73) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (80) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  2 factory          factory app      00 00 00010000 000f0000
I (95) boot: End of partition table
I (100) esp_image: segment 0: paddr=0x00010010 vaddr=0x40210010 size=0x75e7c (482940) map
0x40210010: _stext at ??:?

I (273) esp_image: segment 1: paddr=0x00085e94 vaddr=0x40285e8c size=0x17c9c ( 97436) map
I (307) esp_image: segment 2: paddr=0x0009db38 vaddr=0x3ffe8000 size=0x006a4 (  1700) load
I (308) esp_image: segment 3: paddr=0x0009e1e4 vaddr=0x40100000 size=0x00080 (   128) load
I (314) esp_image: segment 4: paddr=0x0009e26c vaddr=0x40100080 size=0x0568c ( 22156) load
I (330) boot: Loaded app from partition at offset 0x10000
D (338) phy_init: loading PHY init data from application binary
D (357) nvs: nvs_open_from_partition backup_mac 0
D (359) nvs: nvs_get_str_or_blob backup_mac_data
D (362) nvs: nvs_close 1
D (363) system_api: Load MAC from NVS error=0
D (365) reset_reason: RTC reset 2 wakeup 0 store 0, reason is 2
D (369) wdt: Enable task watch dog panic, panic time parameter is 11
D (375) wdt: task watch dog trigger time parameter is 15
dns_init: initializing
tcpip_task_hdlxxx : 3ffedc58, prio:8,stack:2560
D (385) event: running task for loop 0x40106b34
D (389) event: created task for loop 0x40106b34
D (394) event: created event loop 0x40106b34
I (398) system_api: Base MAC address is not set, read default base MAC address from EFUSE
D (406) nvs: nvs_open_from_partition backup_mac 0
D (411) nvs: nvs_get_str_or_blob backup_mac_data
D (416) nvs: nvs_close 2
I (418) system_api: Base MAC address is not set, read default base MAC address from EFUSE
D (426) nvs: nvs_open_from_partition backup_mac 0
D (431) nvs: nvs_get_str_or_blob backup_mac_data
D (435) nvs: nvs_close 3
D (437) phy_init: loading PHY init data from application binary
D (443) nvs: nvs_open_from_partition phy 0
D (447) nvs: nvs_get_str_or_blob cal_data
D (451) nvs: nvs_get_str_or_blob dc_table
D (455) nvs: nvs_close 4
phy_version: 1163.0, 665d56c, Jun 24 2020, 10:00:08, RTOS new
I (503) phy_init: phy ver: 1163_0
D (506) nvs: nvs_open_from_partition misc 1
D (507) nvs: nvs_open_from_partition nvs.net80211 1
D (510) nvs: nvs_get opmode 1
D (513) nvs: nvs_get_str_or_blob sta.ssid
D (517) nvs: nvs_get_str_or_blob sta.mac
D (520) nvs: nvs_get sta.authmode 1
D (523) nvs: nvs_get_str_or_blob sta.pswd
D (527) nvs: nvs_get_str_or_blob sta.pmk
D (531) nvs: nvs_get sta.chan 1
D (534) nvs: nvs_get auto.conn 1
D (537) nvs: nvs_get bssid.set 1
D (540) nvs: nvs_get_str_or_blob sta.bssid
D (544) nvs: nvs_get sta.lis_intval 2
D (547) nvs: nvs_get sta.phym 1
D (550) nvs: nvs_get sta.phybw 1
D (553) nvs: nvs_get_str_or_blob sta.apsw
D (557) nvs: nvs_get_str_or_blob sta.apinfo
D (561) nvs: nvs_get sta.scan_method 1
D (564) nvs: nvs_get sta.sort_method 1
D (567) nvs: nvs_get sta.minrssi 1
D (570) nvs: nvs_get sta.minauth 1
D (573) nvs: nvs_get_str_or_blob ap.ssid
D (577) nvs: nvs_get_str_or_blob ap.mac
D (581) nvs: nvs_get_str_or_blob ap.passwd
D (585) nvs: nvs_get_str_or_blob ap.pmk
D (588) nvs: nvs_get ap.chan 1
D (591) nvs: nvs_get ap.authmode 1
D (594) nvs: nvs_get ap.hidden 1
D (597) nvs: nvs_get ap.max.conn 1
D (600) nvs: nvs_get bcn.interval 2
D (603) nvs: nvs_get ap.phym 1
D (606) nvs: nvs_get ap.phybw 1
D (609) nvs: nvs_get ap.sndchan 1
D (612) nvs: nvs_get lorate 1
D (615) nvs: nvs_get sta.pmf_e 1
D (617) nvs: nvs_get sta.pmf_r 1
D (620) nvs: nvs_get ap.pmf_e 1
D (623) nvs: nvs_get ap.pmf_r 1
D (626) nvs: nvs_get_str_or_blob country
D (630) nvs: nvs_get sta.rm_e 1
D (633) nvs: nvs_get sta.btm_e 1
I (636) example: Setting WiFi configuration SSID TP-Link_2BAB...
D (642) wifi: clear blacklist
D (646) system_event: SYSTEM_EVENT_STA_START
D (649) event: running post WIFI_EVENT:2 with handler 0x4026cb6c on loop 0x40106b34
0x4026cb6c: handle_sta_start at /home/anuj/esp/ESP8266_RTOS_SDK_Latest/components/tcpip_adapter/event_handlers.c:70

D (656) event: running post WIFI_EVENT:2 with handler 0x402249a0 on loop 0x40106b34
0x402249a0: event_handler at /home/anuj/esp/ESP8266_RTOS_SDK_Latest/examples/wifi/wpa2_enterprise/main/wpa2_enterprise_main.c:82

D (664) wifi: nvs=0, ssid=TP-Link_2BAB, channel=5
D (668) wifi: ssid=TP-Link_2BAB match nvs 0, channel=5
D (673) wifi: first chan=5
D (676) wifi: scan_cancel 0
D (678) wifi: scan start 561485
D (682) wifi: scan_op_start 5
D (683) wifi: scan_send_probe
D (686) wifi: ucast probe
D (809) wifi: scan_op_end 7 0
D (810) wifi: enter scan_done 693464 0
I (811) wifi: scandone
D (812) wifi: first chan=1
I (1755) wifi:state: 0 -> 2 (b0)
dns_tmr: dns_check_entries
I (1758) wifi:state: 2 -> 3 (0)
I (1761) wifi:state: 3 -> 5 (10)
I (1855) wifi:state: 5 -> 0 (17a0)
D (1856) system_event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:TP-Link_2BAB, ssid_len:12, bssid:98:da:c4:69:2b:ab, reason:23 (802.1x auth failed)
D (1861) event: running post WIFI_EVENT:5 with handler 0x4026cbb4 on loop 0x40106b34
0x4026cbb4: handle_sta_disconnected at /home/anuj/esp/ESP8266_RTOS_SDK_Latest/components/tcpip_adapter/event_handlers.c:123

D (1868) tcpip_adapter: if0 start ip lost tmr: enter
D (1873) tcpip_adapter: if0 start ip lost tmr: no need start because netif=0x40106f94 interval=120 ip=0
D (1882) event: running post WIFI_EVENT:5 with handler 0x402249a0 on loop 0x40106b34
0x402249a0: event_handler at /home/anuj/esp/ESP8266_RTOS_SDK_Latest/examples/wifi/wpa2_enterprise/main/wpa2_enterprise_main.c:82

D (1889) wifi: nvs=0, ssid=TP-Link_2BAB, channel=5
D (1894) wifi: ssid=TP-Link_2BAB match nvs 0, channel=5
D (1899) wifi: first chan=5
D (1902) wifi: scan_cancel 0
D (1904) wifi: scan start 1788253
D (1907) wifi: scan_op_start 5
D (1910) wifi: scan_send_probe
D (1912) wifi: ucast probe
D (2035) wifi: scan_op_end 3 0
D (2036) wifi: enter oper channel, 1920711
D (2038) wifi: scan_op_start 1
D (2038) wifi: scan_send_probe
D (2039) wifi: ucast probe
D (2160) wifi: scan_op_end 3 0
D (2161) wifi: enter oper channel, 2046025
D (2163) wifi: scan_op_start 2
D (2164) wifi: scan_send_probe
D (2164) wifi: ucast probe
D (2286) wifi: scan_op_end 3 0
D (2287) wifi: enter oper channel, 2171114
D (2288) wifi: scan_op_start 3
D (2289) wifi: scan_send_probe
D (2290) wifi: ucast probe
dns_tmr: dns_check_entries
D (2411) wifi: scan_op_end 3 0
D (2412) wifi: enter oper channel, 2296195
D (2413) wifi: scan_op_start 4
D (2414) wifi: scan_send_probe
D (2415) wifi: ucast probe
D (2536) wifi: scan_op_end 3 0
D (2537) wifi: enter oper channel, 2421329
D (2538) wifi: scan_op_start 6
D (2539) wifi: scan_send_probe
D (2540) wifi: ucast probe
D (2661) wifi: scan_op_end 3 0
D (2662) wifi: enter oper channel, 2546431
D (2663) wifi: scan_op_start 7
D (2664) wifi: scan_send_probe
D (2665) wifi: ucast probe
D (2786) wifi: scan_op_end 3 0
D (2787) wifi: enter oper channel, 2671529
D (2789) wifi: scan_op_start 8
D (2789) wifi: scan_send_probe
D (2790) wifi: ucast probe
D (2911) wifi: scan_op_end 3 0
D (2912) wifi: enter oper channel, 2796664
D (2914) wifi: scan_op_start 9
D (2914) wifi: scan_send_probe
D (2915) wifi: ucast probe
D (3036) wifi: scan_op_end 3 0
D (3037) wifi: enter oper channel, 2921768
D (3038) wifi: scan_op_start 10
D (3039) wifi: scan_send_probe
D (3040) wifi: ucast probe
D (3161) wifi: scan_op_end 3 0
D (3162) wifi: enter oper channel, 3046877
D (3163) wifi: scan_op_start 11
D (3164) wifi: scan_send_probe
D (3165) wifi: ucast probe
D (3286) wifi: scan_op_end 3 0
D (3287) wifi: enter oper channel, 3172018
D (3289) wifi: scan_op_start 12
dns_tmr: dns_check_entries
D (3649) wifi: scan_op_end 3 0
D (3650) wifi: enter oper channel, 3535886
D (3652) wifi: scan_op_start 13
D (4013) wifi: scan_op_end 3 0
D (4014) wifi: enter oper channel, 3899720
D (4015) wifi: enter scan_done 3900669 0
I (4016) wifi: scandone
D (4017) wifi: first chan=1
D (4019) wifi: clear blacklist
D (4021) system_event: SYSTEM_EVENT_STA_DISCONNECTED, ssid:TP-Link_2BAB, ssid_len:12, bssid:00:00:00:00:00:00, reason:205 (other reason)
D (4033) wifi: clear blacklist
D (4037) event: running post WIFI_EVENT:5 with handler 0x4026cbb4 on loop 0x40106b34
0x4026cbb4: handle_sta_disconnected at /home/anuj/esp/ESP8266_RTOS_SDK_Latest/components/tcpip_adapter/event_handlers.c:123

Attached Items:

• sdkconfig file
• Full Debug Logs
  sdkconfig.zip
  wpa_enterprise.log

[SaurabhCoolR]

Here is the Radius Server Msg:

Authentication Details: Connection Request Policy Name: Secure Wireless Controllers Network Policy Name: Stores Secure Wireless Policy Authentication Provider: Windows Authentication Server: Authentication Type: PEAP EAP Type: - Account Session Identifier: 43434530393946454142464636423033 Logging Results: Accounting information was written to the local log file. Reason Code: 262 Reason: The supplied message is incomplete. The signature was not verified.

[SaurabhCoolR]

From further Tests, we have found that with SDK v3.4:

--> Working with Freeradius v3.0.20 and above with basic setup running on Ubuntu.
--> Not working with Windows Server 2012 R2 NPS (RADIUS) with following error:

Authentication Details:
Connection Request Policy Name: Secure Wireless Controllers
Network Policy Name: Stores Secure Wireless Policy
Authentication Provider: Windows
Authentication Type: PEAP
EAP Type: -
Account Session Identifier: 43434530393946454142464636423033
Logging Results: Accounting information was written to the local log file.
Reason Code: 262
Reason: The supplied message is incomplete. The signature was not verified.

Note: We don't provide the domain name in example ID configuration. We give the same as Username cause that's what was working with earlier SDK. Will that cause an issue in new SDK v3.4?

[nishanth-radja]

@SaurabhCoolR The reason code 262 on windows server could mean any of these.
1.Are the CA cert expired on windows server?
2.Is the Validate server option enabled on the client i.e is the CA flashed on the DUT? Can you also try without flashing.
3.Any windows update was done recently?
4.Are other client able to connect using the radius server or is it just this DUT having the issue?

Pls refer to this link "https://community.spiceworks.com/topic/1342663-nps-server-certificate"

[SaurabhCoolR]

Hi @nishanth-radja.

1. Are the CA cert expired on windows server?
   Ans: We are not doing CA cert validation so this should be irrelevant?. As you can see in screenshot above, we have commented out the CA cert verification part in the example code.

2.Is the Validate server option enabled on the client i.e is the CA flashed on the DUT? Can you also try without flashing.
Ans: We are not using it even though it is flashed. So flashing CA in DUT should be irrelevant if we have commented out it's use in code, right?

3.Any windows update was done recently?
Ans: Will confirm for this.

4.Are other client able to connect using the radius server or is it just this DUT having the issue?
Ans: Yes the other devices are able to connect to it fine. Our PEAP device based on SDK commit 655f934 is able to connect with it fine.
Problem only with SDK v3.4.

[nishanth-radja]

@SaurabhCoolR Also can you pls provide the correct domain and username in the ID configuration that is the entered in Active directory of the windows.Else the windows will reject the authentication.

[SaurabhCoolR]

Hi @nishanth-radja,

Please find the needed details:

winlog.event_data.SubjectDomainName --> DHC
winlog.event_data.SubjectUserName --> SVSHLFWIFI001A

In the sdk v3.4 WPA2 Example Code, We are giving following config in Menuconfig:

EXAMPLE_EAP_ID --> SVSHLFWIFI001A
EXAMPLE_EAP_USERNAME --> SVSHLFWIFI001A

Also we have following Difference in Radius Server Log for working case with earlier SDK and non working SDK v3.4 Example:
Working Case:
winlog.event_data.EAPType --> Microsoft: Secured password (EAP-MSCHAP v2)
Non Working Case:
winlog.event_data.EAPType --> ""

[Rainbow-Cai]

Hi @nishanth-radja ,Could you please provide some help?

[nishanth-radja]

@SaurabhCoolR Looks like the EAP_type is going as blank,Do you have sniffer captures for both working and not working case.
Do you have the full radius logs of the working and non working case?Can you pls share them.
Also try this eap_id and username.
EXAMPLE_EAP_ID --> SVSHLFWIFI001A@DHC.com
EXAMPLE_EAP_USERNAME --> SVSHLFWIFI001A
EXAMPLE_EAP_password --> "correct password"

[SaurabhCoolR]

Hi @nishanth-radja :

We are working on getting the full radius logs.

We tried with suggested EAP Credetentials but it doesn't seem to work and giving same Auth Fail issue.

[nishanth-radja]

@SaurabhCoolR sure,Pls get the sniffer capture too along with the radius logs for the working and non working case .

[SaurabhCoolR]

Hi @nishanth-radja :

We are working on the same.

Meanwhile can you please confirm which specific packets you need? We are using Wireshark to capture the packets.
This will help us to capture only the needed packets and not dump unnecessary traffic capture over here.

[SaurabhCoolR]

Hi @nishanth-radja :

Here attaching the K12 Text Files of Wireshark sniffer capture of the Radius Packets for both success and failed cases. Please have a look.

Thanks.
old_sdk_success2.txt
old_sdk_success1.txt
new_sdk_failed2.txt
new_sdk_failed1.txt

[kapilkedawat]

Hi @SaurabhCoolR Can you please add this fix and retry? espressif/esp-idf@6647f48

[SaurabhCoolR]

Hi,

Tried with the mentioned changes above, but still radius connection failed.
Please find the attached reference files.

new_sdk_failed4.txt
new_sdk_failed3.txt