Client debug for WPA/WPA2 with Pre-Shared Key

Today in this article I will be talking about the step by step process when clients connect to any SSID. The traffic is centrally switched in this case meaning my traffic will go from client to AP>>Switch>>WLC and then the response will come back.

So in this case my client has the mac address d0:37:45:88:d8:a3 and I have created the SSID TEST_2020 for my client.

AP Name: AP00A3.8EFA.D0D4 

AP MAC: 00:a3:8e:fa:d0:d4  

BSSID : 40:ce:24:ca:ee:89

Client Mac : d0:37:45:88:d8:a3

********************************************************

SSID Configuration:

L2 Security === WPA+WPA2

WPA+ WPA2 parameters

WPA2 policy enable

WPA2 encryption    AES

Authentication key management

PSK

This authentication L2 authentication where first the authentication will take place and then the client will get the IP address.

**************************************************************************

I have initiated the debug message from my WLC for my client with mac address d0:37:45:88:d8:a3.

One important note when the client finds an SSID that matches its configuration, it will send an authentication request probe. Important to note is that the authentication request and response probes exchanged in this phase don’t provide encryption. That function is implemented by the 4-way handshake. Here, the authentication request and response exchange is only used to register the client’s MAC address. This information is also used in case MAC filtering is implemented. If the client is allowed to connect to the network, it will associate to the access point with the stronger signal. That initial request and response is nothing but the probe request and response. That two packets is not in the debug so I have explained it here in the starting itself.

AP-------Switch--------WLC. Wireless PC

(Cisco Controller) >*apfOpenDtlSocket: Sep 30 22:29:17.209: d0:37:45:88:d8:a3 Received management frame ASSOCIATION REQUEST on BSSID 40:ce:24:ca:ee:89 destination addr 40:ce:24:ca:ee:89

So you can see from the very first line that the client is sending association request that is nothing but the management frame,

*apfMsConnTask_6: Sep 30 22:29:17.211: d0:37:45:88:d8:a3 Processing assoc-req station:d0:37:45:88:d8:a3 AP:40:ce:24:ca:ee:80-00 ssid : TEST_2020 thread:1b830598

*apfMsConnTask_6: Sep 30 22:29:17.211: d0:37:45:88:d8:a3 Adding mobile on LWAPP AP 40:ce:24:ca:ee:80(0)

A new station is received. After validating type, it is added to the AP that received it. This can happen both on processing association request or probe requests

*apfMsConnTask_6: Sep 30 22:29:17.211: d0:37:45:88:d8:a3 Created Acct-Session-ID (5f7506bd/d0:37:45:88:d8:a3/15) for the mobile

AP will create the Association ID for the specific client. It will be different for different clients.

*apfMsConnTask_6: Sep 30 22:29:17.211: d0:37:45:88:d8:a3 Association received from mobile on BSSID 40:ce:24:ca:ee:89 AP AP00A3.8EFA.D0D4

Client made new Association to AP/BSSID BSSID 40:ce:24:ca:ee:89 AP AP00A3.8EFA.D0D4

*apfMsConnTask_6: Sep 30 22:29:17.212: d0:37:45:88:d8:a3 STA - rates (12): 130 132 139 150 12 18 24 36 48 72 96 108 0 0 0 0

*apfMsConnTask_6: Sep 30 22:29:17.212: d0:37:45:88:d8:a3 Processing RSN IE type 48, length 20 for mobile d0:37:45:88:d8:a3

The WLC/AP has found from client association request Information Element that claims PMKID Caching support

*apfMsConnTask_6: Sep 30 22:29:17.213: d0:37:45:88:d8:a3 0.0.0.0 AUTHCHECK (2) Change state to 8021X_REQD (3) last state AUTHCHECK (2)

Client is entering the 802.1x or PSK Authentication state, in our case its PSK . As I am using PSK for my SSID.

*apfMsConnTask_6: Sep 30 22:29:17.213: d0:37:45:88:d8:a3 apfMsAssoStateInc

Client has successfully cleared AP association phase.

*apfMsConnTask_6: Sep 30 22:29:17.213: d0:37:45:88:d8:a3 apfMsWepPskStateInc

Client is entering PSK Dot1x or WEP authentication phase

*apfMsConnTask_6: Sep 30 22:29:17.213: d0:37:45:88:d8:a3 Sending assoc-resp with status 0 station:d0:37:45:88:d8:a3 AP:40:ce:24:ca:ee:80-00 on apVapId 10

WLC/AP is sending an Association Response to the client with status code 0 = Successful association

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.220: d0:37:45:88:d8:a3 Sending EAPOL-Key Message to mobile d0:37:45:88:d8:a3 state INITPMK (message 1), replay counter 00.00.00.00.00.00.00.00

4-Way PTK Handshake, Sending M1------ From here the EAPOL handshake will start.

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.231: d0:37:45:88:d8:a3 Received EAPOL-key in PTK_START state (message 2) from mobile d0:37:45:88:d8:a3

4-Way PTK Handshake, Received M2

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.232: d0:37:45:88:d8:a3 Sending EAPOL-Key Message to mobile d0:37:45:88:d8:a3 state PTKINITNEGOTIATING (message 3), replay counter 00.00.00.00.00.00.00.01

4-Way PTK Handshake, Sending M3

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3 Received EAPOL-key in PTKINITNEGOTIATING state (message 4) from mobile d0:37:45:88:d8:a3

4-Way PTK Handshake, Received M4

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3 apfMs1xStateInc

Client has completed PSK Dot1x or WEP authentication phase,now the autheticaton phase compleetd and since its L2 authetication so after authetication the client will get the IP address.

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3    Client Ip: 0.0.0.

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3    Client Vlan Ip: 10.2.1.10, Vlan mask : 255.255.255.0

 *Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3    Client Vap Security: 1073758208

 *Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3    Virtual Ip: 192.0.2.1

 *Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3    ssid: TEST_2020

 *Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3  Building VlanIpPayload.

*Dot1x_NW_MsgTask_3: Sep 30 22:29:17.244: d0:37:45:88:d8:a3 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)

Client has entered DHCP Required state

*DHCP Socket Task: Sep 30 22:29:17.279: d0:37:45:88:d8:a3 DHCP received op BOOTREQUEST (1) (len 308,vlan 0, port 2, encap 0xec03, xid 0x689aa758)

Received DHCP request from client

*DHCP Socket Task: Sep 30 22:29:17.281: d0:37:45:88:d8:a3 DHCP processing DHCP OFFER (2)

DHCP Socket Task: Sep 30 22:29:17.282: d0:37:45:88:d8:a3 DHCP Opt82 bridge mode insertion enabled, inserts opt82 if opt82 is enabled vlan=1, datalen =18, optlen=64

*DHCP Socket Task: Sep 30 22:29:17.283: d0:37:45:88:d8:a3 DHCP successfully bridged packet to DS

*DHCP Socket Task: Sep 30 22:29:17.284: d0:37:45:88:d8:a3 DHCP received op BOOTREPLY (2) (len 315,vlan 1, port 1, encap 0xec00, xid 0xeecb0f10)

*DHCP Socket Task: Sep 30 22:29:17.285: d0:37:45:88:d8:a3 DHCP processing DHCP OFFER (2)

*DHCP Socket Task: Sep 30 22:29:17.286: d0:37:45:88:d8:a3 DHCP  op: BOOTREPLY, htype: Ethernet, hlen: 6, hops: 0

Received DHCP OFFER from DHCP server

*DHCP Socket Task: Sep 30 22:29:17.290: d0:37:45:88:d8:a3 DHCP Opt82 bridge mode insertion enabled, inserts opt82 if opt82 is enabled vlan=1, datalen =18, optlen=92

*DHCP Socket Task: Sep 30 22:29:17.291: d0:37:45:88:d8:a3 DHCP successfully bridged packet to DS

*DHCP Socket Task: Sep 30 22:29:17.292: d0:37:45:88:d8:a3 DHCP received op BOOTREPLY (2) (len 315,vlan 1, port 1, encap 0xec00, xid 0xeecb0f10)

Received DHCP ACK from DHCP server

*DHCP Socket Task: Sep 30 22:29:17.293: d0:37:45:88:d8:a3 apfMsRunStateInc

The client has entered RUN state

DHCP Socket Task: Sep 30 22:29:17.295: d0:37:45:88:d8:a3 10.2.1.107 DHCP_REQD (7) Change state to RUN (20) last state DHCP_REQD (7)

Received DHCP ACK, assigning IP Address 10.2.1.107

Summary:

++Client made a new association to AP/BSSID

++The WLC/AP has found client association request information element that claims PMKID caching support.

++Client is entering the 802.1x or PSK Authentication state

++Client has successfully cleared the AP association phase

++WLC/AP is sending an Association Response to the client with status code 0 = Successful association

++4-Way PTK Handshake, Sending M1

++4-Way PTK Handshake, Received M2

++4-Way PTK Handshake, Sending M3

++4-Way PTK Handshake, Received M4

++Client has completed PSK Dot1x or WEP authentication phase

++Client has entered DHCP Required state

++Received DHCP request from the client

++Received DHCP OFFER from DHCP server

++Received DHCP request from the client

++Received DHCP ACK from DHCP server

++Client has entered RUN state

++Received DHCP ACK, assigning IP Address 10.2.1.107

Note :

Technically the process of connecting the client with any SSID with the WPA+WPA2 PSK configuration will be the same. There might be a slight terminology difference based on the wireless product.