Guest Auth issue

[ittechk4u1]

Hello Experts,

I am using cisco mobility express AP"2802" as WLC.

Created a Guest wlan with custom webpage and authentication using radius server.

I can see that Clinet is getting authenticating in ise but client is getting error "The User name and password combination you have entered is invalid. "

Here are the debug logs:

(WLC1) >*emWeb: Mar 01 11:53:56.397: Authentication succeeded for - root on 10.18.20.9
*apfReceiveTask: Mar 01 11:54:07.855: ca:cb:31:95:a4:11 Received management frame ASSOCIATION REQUEST on BSSID cc:db:93:79:be:ae destination addr cc:db:93:79:be:ae slotid 1
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Updating the client capabiility as 4
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Processing assoc-req station:ca:cb:31:95:a4:11 AP:cc:db:93:79:be:a0-01 ssid : XYZGuest thread:5d6bdd20
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 apfCreateMobileStationEntryWrapper (apf_ms.c:4510) Changing state for mobile ca:cb:31:95:a4:11 on AP cc:db:93:79:be:a0 from Idle to Idle

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Adding mobile on LWAPP AP cc:db:93:79:be:a0(1)
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Created Acct-Session-ID (603cc7cf/ca:cb:31:95:a4:11/26) for the mobile
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Setting hasApChnaged Flag as true. It is a fresh assoc request.

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 req rcv on open Wlan
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Setting RTTS enabled to 0
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Association received from mobile on BSSID cc:db:93:79:be:ae AP AARAP001
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Station: CA:CB:31:95:A4:11 trying to join WLAN with RSSI -72. Checking for XOR roam conditions on AP: CC:DB:93:79:BE:A0 Slot: 1
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Station: CA:CB:31:95:A4:11 is associating to AP CC:DB:93:79:BE:A0 which is not XOR roam capable
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Global 200 Clients are allowed to AP radio

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Max Client Trap Threshold: 0 cur: 1

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Rf profile 600 Clients are allowed to AP wlan

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Updated local bridging VLAN to 0 while applying WLAN policy
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Updated session timeout to 0 and Sleep timeout to 720 while applying WLAN policy
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 override for default ap group, marking intgrp NULL
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 0 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 Not re-applying interface policy for local switching Client

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 After applying Interface(management) policy on Mobile, role Unassociated. Ms NAC State 2 Quarantine Vlan 0 Access Vlan 0

*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 0.0.0.0 START (0) Changing IPv4 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3486)
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 0.0.0.0 START (0) Changing Url ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255),Default action is '0' --- (caller apf_policy.c:3506)
*apfMsConnTask_0: Mar 01 11:54:07.856: ca:cb:31:95:a4:11 0.0.0.0 START (0) Changing IPv6 ACL 'none' (ACL ID 255) ===> 'none' (ACL ID 255) --- (caller apf_policy.c:3527)
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Values before applying NASID - interfacetype:0, ovrd:0, mscb nasid:, interface nasid:, APgrpset:0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 apfApplyWlanPolicy: Apply WLAN Policy over PMIPv6 Client Mobility Type, Tunnel User - 0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Check before Setting the NAS Id to WLAN specific Id ''
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 apf_policy.c:2771 Assigning the SGT 0 to mobile (earlier sgt 0)
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 In processSsidIE:7640 setting Central switched to FALSE
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Disabling flexconnect central association for the client
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Applying site-specific Local Bridging override for station ca:cb:31:95:a4:11 - vapId 2, site 'default-group', interface 'management'
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Applying Local Bridging Interface Policy for station ca:cb:31:95:a4:11 - vlan 0, interface id 0, interface 'management', nasId:''
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Set Client Non AP specific WLAN apfMsAccessVlan = 172
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 This apfMsAccessVlan may be changed later from AAA after L2 Auth
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Cleared localSwitchingVlan, may be assigned later based on AAA override
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 processSsidIE statusCode is 0 and status is 0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 processSsidIE ssid_done_flag is 0 finish_flag is 0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 STA - rates (8): 140 18 152 36 176 72 96 108 0 0 0 0 0 0 0 0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 suppRates statusCode is 0 and gotSuppRatesElement is 1
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Assigning flex webauth IPv4-ACL ID :65535, IPv6-ACL ID:65535 for AP WLAN ID : 2
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Assigned flex post-auth IPv4-ACL ID :65535, IPv6-ACL ID:65535 for AP WLAN ID : 2
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Updating AID for REAP AP Client cc:db:93:79:be:a0 - AID ===> 1
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Assoc Req BSSID cc:db:93:79:be:ae AP(AARAP001) slot 1 ssid (XYZGuest) Tmstmp 5632 AID 1 stCode 0/0 apChngd 0 oldAp 00:00:00:00:00:00
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 START (0) Initializing policy
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 START (0) Change state to AUTHCHECK (2) last state START (0)

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 apfVapSecurity=0x10 L2=0 SkipWeb=0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 AuthenticationRequired = 1
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 AUTHCHECK (2) Change state to L2AUTHCOMPLETE (4) last state AUTHCHECK (2)

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Flex Central Auth Client
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 L2AUTHCOMPLETE (4) DHCP required on AP cc:db:93:79:be:a0 vapId 2 apVapId 2for this client
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Not Using WMM Compliance code qosCap 00
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 flex webauth acl id to be sent :65535 name : client acl id :65535 name :
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 flex webauth ipv6 acl id to be sent :65535 name : client acl id :65535 name :
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Vlan while overriding the policy = -1
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 sending to spamAddMobile vlanId -1 aclName = , flexAclId 65535

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 L2AUTHCOMPLETE (4) Plumbed mobile LWAPP rule on AP cc:db:93:79:be:a0 vapId 2 apVapId 2 flex acl-name: v6acl-name
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 L2AUTHCOMPLETE (4) Change state to DHCP_REQD (7) last state L2AUTHCOMPLETE (4)

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) pemApfAddMobileStation2 4276, Adding TMP rule
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 Mobility peer ip is 0, failed to get session type

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Adding Fast Path rule
type = Airespace AP - Learn IP address
on AP cc:db:93:79:be:a0, slot 1, interface = 1, QOS = 2
IPv4 ACL ID = 255, IPv
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 46, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfMsConnTask_0: Mar 01 11:54:07.857: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfMsConnTask_0: Mar 01 11:54:07.858: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*apfMsConnTask_0: Mar 01 11:54:07.858: ca:cb:31:95:a4:11 Updating info change db with CMX bitmap 0x0000
*apfMsConnTask_0: Mar 01 11:54:07.858: ca:cb:31:95:a4:11 apfMsAssoStateInc
*apfMsConnTask_0: Mar 01 11:54:07.858: ca:cb:31:95:a4:11 apfPemAddUser2 (apf_policy.c:465) Changing state for mobile ca:cb:31:95:a4:11 on AP cc:db:93:79:be:a0 from Idle to Associated

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 apfPemAddUser2:session timeout forstation ca:cb:31:95:a4:11 - Session Tout 0, apfMsTimeOut '0' and sessionTimerRunning flag is 0
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Stopping deletion of Mobile Station: (callerId: 48)
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Func: apfPemAddUser2, Ms Timeout = 0, Session Timeout = 0

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Sending assoc-resp with status 0 station:ca:cb:31:95:a4:11 AP:cc:db:93:79:be:a0-01 on apVapId 2
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 VHT Operation IE: width 80/1 ch 64 freq0 58 freq1 0 msc0 0xff msc1 0xff
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Sending Assoc Response (status: '0') to station on AP AARAP001 on BSSID cc:db:93:79:be:ae ApVapId 2 Slot 1, mobility role 0
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 apfProcessAssocReq (apf_80211.c:12921) Changing state for mobile ca:cb:31:95:a4:11 on AP cc:db:93:79:be:a0 from Associated to Associated

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Mobility query, PEM State: DHCP_REQD

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) NO release MSCB
*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Building Mobile Announce :

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Building Client Payload:

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Client Ip: 0.0.0.0

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Client Vlan Ip: 10.40.80.1, Vlan mask : 255.255.255.0

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Client Vap Security: 16

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Virtual Ip: 192.0.2.1

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 ssid: XYZGuest

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Building Client profile name Payload:

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Profile Name: XYZGuest

*apfMsConnTask_0: Mar 01 11:54:07.861: ca:cb:31:95:a4:11 Building VlanIpPayload.

*pemReceiveTask: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Add SGT:0 to AP cc:db:93:79:be:a0
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Add CTS mobile SGT - Encoded the capwap payload for the mobile with SGT 0
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 MS IP NULL during AddMobile, not sending IP Distribution
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Flex Ipv6 pre-auth acl is not present, not Encoding Flex Ipv6 acl for add mobile Payload
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Flex Ipv6 post auth acl is not present, not updating add mobile Payload
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Successful transmission of LWAPP Add-Mobile to AP cc:db:93:79:be:a0 slotId 1 idx@94
*spamApTask0: Mar 01 11:54:07.862: ca:cb:31:95:a4:11 Setting ADD_MOBILE (idx 95, action 0, last count 0) ack state for STA on AP cc:db:93:79:be:a0
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) mobility role update request from Unassociated to Local
Peer = 0.0.0.0, Old Anchor = 0.0.0.0, New Anchor = 10.40.80.1
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 Created Cisco-Audit-Session-ID for the mobile: 0150280a0000000dcfc73c60 type: local
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 Audit session id is created 0150280a0000000dcfc73c60 for mobility complete
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 pemAdvanceState2 (pem_api.c:6869) Changing state for mobile ca:cb:31:95:a4:11 on AP cc:db:93:79:be:a0 from Associated to Associated

*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) State Update from Mobility-Incomplete to Mobility-Complete, mobility role=Local, client state=APF_MS_STATE_ASSOCIATED
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) pemAdvanceState2 7003, Adding TMP rule
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 Mobility peer ip is 0, failed to get session type

*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Replacing Fast Path rule
type = Airespace AP - Learn IP address
on AP cc:db:93:79:be:a0, slot 1, interface = 1, QOS = 2
IPv4 ACL ID = 255,
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) 802.1P = 0, DSCP = 46, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 Updating info change db with CMX bitmap 0x0000
*apfReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 DHCP_REQD (7) NO release MSCB
*pemReceiveTask: Mar 01 11:54:07.864: ca:cb:31:95:a4:11 0.0.0.0 Added NPU entry of type 9, dtlFlags 0x0
*apfReceiveTask: Mar 01 11:54:07.866: ca:cb:31:95:a4:11 Received management frame ACTION on BSSID cc:db:93:79:be:ae destination addr cc:db:93:79:be:ae slotid 1
*apfMsConnTask_0: Mar 01 11:54:07.866: ca:cb:31:95:a4:11 Got action frame from the client (ActionCategory:5), payloadLen:17
*apfMsConnTask_0: Mar 01 11:54:07.866: ca:cb:31:95:a4:11 Found RM action category code
*apfMsConnTask_0: Mar 01 11:54:07.866: ca:cb:31:95:a4:11 Station: CA:CB:31:95:A4:11 sent 802.11K neighbor request to AP CC:DB:93:79:BE:A0
*apfMsConnTask_0: Mar 01 11:54:07.866: ca:cb:31:95:a4:11 Station: CA:CB:31:95:A4:11 requested neighbors on non XOR roam capable AP CC:DB:93:79:BE:A0 Slot 1
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 IPv4 Addr: 0:0:0:0

*CAPWAP DATA: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 IAPP-IP-UPDATE(0):891 Bytes received for client
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 Recieved MS IPv4 Addr= 172.28.40.233
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 Not updating IPv4 Addr, as client is not in RUN state
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 Recieved IPv6 addresses count: 1
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 Updating MS IPv6[1] Addr= fe80:0000:0000:0000:c8cb:31ff:fe95:a411
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 1, add_or_delete 1
*apfReceiveTask: Mar 01 11:54:08.091: ca:cb:31:95:a4:11 IPv4 Addr: 172:28:40:233

*apfReceiveTask: Mar 01 11:54:08.092: IP Context distribution - event: (DHCP IP LEARN) msCount: 1 ToAllAps: 1
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 IP context distribution applicable for LSW, dhcp_reqd enabled wlans not sending for WLAN: 2
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 dtlArpInsert: Add ARP entry IP 172.28.40.233, MAC ca:cb:31:95:a4:11, VLAN 0, INTF 1, Type 0, New 1 (caller apf_foreignap.c:1186)
,arp count = 1
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 dtlArpSetType: Changing ARP Type from 0 ---> 1 for station ca:cb:31:95:a4:11
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 DHCP_REQD (7) Change state to WEBAUTH_REQD (8) last state DHCP_REQD (7)

*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) pemAdvanceState2 7845, Adding TMP rule
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 Mobility peer ip is 0, failed to get session type

*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Replacing Fast Path rule
type = Airespace AP Client - ACL passthru
on AP cc:db:93:79:be:a0, slot 1, interface = 1, QOS = 2
IPv4 AC
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Fast Path rule (contd...) 802.1P = 0, DSCP = 46, TokenID = 1706, IntfId = 0 Local Bridging Vlan = 0, Local Bridging intf id = 0
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Fast Path rule (contd...) AVC Ratelimit: AppID = 0 ,AppAction = 0, AppToken = 1706 AverageRate = 0, BurstRate = 0

*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Successfully plumbed mobile rule (IPv4 ACL ID 255, IPv6 ACL ID 255, L2 ACL ID 255,URL ACL ID 255,URL ACL Action 0)
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 Updating info change db with CMX bitmap 0x0000
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 Plumbing web-auth redirect rule due to user logout
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) NO release MSCB
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 Assigning Address 172.28.40.233 to mobile
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 DHCP success event for client. Clearing dhcp failure count for interface management.
*apfReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 DHCP success event for client. Clearing dhcp failure count for interface management.
*pemReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 172.28.40.233 Added NPU entry of type 2, dtlFlags 0x0
*pemReceiveTask: Mar 01 11:54:08.092: ca:cb:31:95:a4:11 Pushing IPv6: fe80:0000:0000:0000:c8cb:31ff:fe95:a411 , intfId:0 and MAC: CA:CB:31:95:A4:11 , Binding to Data Plane. SUCCESS !!
*apfReceiveTask: Mar 01 11:54:08.134: ca:cb:31:95:a4:11 WcdbClientUpdate: IP Binding from WCDB ip_learn_type 2, add_or_delete 1
*apfReceiveTask: Mar 01 11:54:08.134: ca:cb:31:95:a4:11 IPv4 Addr: 172:28:40:233

*apfReceiveTask: Mar 01 11:54:08.134: ca:cb:31:95:a4:11 Subnet mismatches while registering IP address 172.28.40.233 with netmask 255.255.255.0 for client ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:08.962: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:12.647: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:12.738: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:13.714: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:13.733: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*emWeb: Mar 01 11:54:13.831: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*emWeb: Mar 01 11:54:13.903: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*emWeb: Mar 01 11:54:14.702: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:14.907: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:15.708: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*emWeb: Mar 01 11:54:36.406: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*ewmwebWebauth1: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Username entry (adef) created for mobile, length = 4
*ewmwebWebauth1: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Username entry (adef) created in mscb for mobile, length = 4
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Normal Response code for AAA Authentication : -9
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 radiusServerFallbackPassiveStateUpdate: RADIUS server is not-ready 10.18.21.14 port 1812 index 0 active 0
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 radiusServerFallbackPassiveStateUpdate: RADIUS server is not-ready 10.18.21.15 port 1812 index 1 active 1
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Found a server : 10.18.21.15 from the WLAN server list of radius server index 2
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Send Radius Auth Request with pktId:3 into qid:1 of server at index:1
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Sending the packet to v4 host 10.18.21.15:1812 of length 245
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 Successful transmission of Authentication Packet (pktId 3) to 10.18.21.15:1812 from server queue 1, proxy state ca:cb:31:95:a4:11-00:00
*aaaQueueReader: Mar 01 11:54:36.407: ca:cb:31:95:a4:11 User entry not found in the Local FileDB for the client.
*radiusTransportThread: Mar 01 11:54:41.592: ca:cb:31:95:a4:11 Retransmit the 'Access-Request' (id 3) to 10.18.21.15 (port 1812, qid 1) reached for mobile. msg retx 1 srvr retx 0 srvr evt 2 srvr tried 0
*radiusTransportThread: Mar 01 11:54:41.592: ca:cb:31:95:a4:11 Sending the packet to v4 host 10.18.21.15:1812 of length 245
*radiusTransportThread: Mar 01 11:54:41.592: ca:cb:31:95:a4:11 Successful transmission of Authentication Packet (pktId 3) to 10.18.21.15:1812 from server queue 1, proxy state ca:cb:31:95:a4:11-00:00
*radiusTransportThread: Mar 01 11:54:46.799: ca:cb:31:95:a4:11 Retransmit the 'Access-Request' (id 3) to 10.18.21.15 (port 1812, qid 1) reached for mobile. msg retx 2 srvr retx 2 srvr evt 2 srvr tried 0
*radiusTransportThread: Mar 01 11:54:46.799: ca:cb:31:95:a4:11 Sending the packet to v4 host 10.18.21.15:1812 of length 245
*radiusTransportThread: Mar 01 11:54:46.799: ca:cb:31:95:a4:11 Successful transmission of Authentication Packet (pktId 3) to 10.18.21.15:1812 from server queue 1, proxy state ca:cb:31:95:a4:11-00:00
*radiusTransportThread: Mar 01 11:54:52.006: ca:cb:31:95:a4:11 Retransmit the 'Access-Request' (id 3) to 10.18.21.15 (port 1812, qid 1) reached for mobile. msg retx 3 srvr retx 5 srvr evt 2 srvr tried 0
*radiusTransportThread: Mar 01 11:54:52.006: ca:cb:31:95:a4:11 Sending the packet to v4 host 10.18.21.15:1812 of length 245
*radiusTransportThread: Mar 01 11:54:52.006: ca:cb:31:95:a4:11 Successful transmission of Authentication Packet (pktId 3) to 10.18.21.15:1812 from server queue 1, proxy state ca:cb:31:95:a4:11-00:00
*radiusTransportThread: Mar 01 11:54:53.608: Radius Passive Fallback - Auth server is not ready 10.18.21.15 port 1812
*radiusTransportThread: Mar 01 11:54:53.609: Radius Passive Fallback - Acct server is not ready 10.18.21.15 port 1813
*radiusTransportThread: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Error Response code for AAA Authentication : -5
*radiusTransportThread: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Normal Response code for AAA Authentication : -7
*radiusTransportThread: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Returning AAA Error 'No Server' (-7) for mobile ca:cb:31:95:a4:11 serverIdx 1
*ewmwebWebauth1: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Plumbing web-auth redirect rule due to user logout
*ewmwebWebauth1: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Web Authentication failure for station
*ewmwebWebauth1: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 172.28.40.233 WEBAUTH_REQD (8) Reached ERROR: from line 7636
*ewmwebWebauth1: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Username entry 'adef' is deleted for mobile from the UserName table
*ewmwebWebauth1: Mar 01 11:54:53.609: ca:cb:31:95:a4:11 Username entry adef deleted for mobile
*emWeb: Mar 01 11:54:53.806: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:54.813: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:54.829: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11
*webauthRedirectME: Mar 01 11:54:54.879: ca:cb:31:95:a4:11 dtlArpFindMobile: ARP Lookup succeeded for 172.28.40.233 / ca:cb:31:95:a4:11

what could be the reason ?

Switch Port config where AP/WLC is connected:

interface GigabitEthernet3/0/43
switchport trunk native vlan 80
switchport trunk allowed vlan 80,92,172
switchport mode trunk

Info: Ping from WLC to both ISE server are working.

Thanks in advance

[Nicolas Poirier · Accepted solution]

Hello,

According to the log, the first RADIUS request and the retransmission from the WLC received no answer fron the ISE Server.

I would check the RADIUS livelog on ISE to see if everything is fine (WLC added as a NAD, no RADIUS key mismatch, etc.).

[Sandeep Choudhary · Accepted solution]

As per logs...ISE server are not responding back!

Please check the NAD config, share secret!!

Also let us know the software version you are running on Ap/WLC?

Regards

Dont forget to rate helpful posts

[ittechk4u1]

Thanks @Sandeep Choudhary @Nicolas Poirier 

I check twice and can confirm that WLC already added as NAD and shared secret  is same on both device.

I am running cisco 8.10.142.0 version on AP/WLC.

Thanks for your help.

[Sandeep Choudhary · Accepted solution]

can you run these commands on WLC:

test aaa radius username <username> password <Password >wlan-id <wlan id>

then run  test aaa show radius

Also can you check if something is blocking (on firewall may be!!) in between ISE and WLC!!

Regards

Dont forget to rate helpful posts

[ittechk4u1]

Hello Sandeep

Please the output of the commands:

-----

(WLC1) >test aaa radius username guest1 password abcde12 wlan-id 3

Radius Test Request
Wlan-id........................................ 3
ApGroup Name................................... none

Attributes Values
---------- ------
User-Name guest1
Called-Station-Id 00-00-00-00-00-00:XYZGuest
Calling-Station-Id 00-11-22-33-44-55
Nas-Port 0x00000001 (1)
Nas-Ip-Address 192.68.80.1
NAS-Identifier WLC1
Airespace / WLAN-Identifier 0x00000002 (2)
User-Password abcde12
Service-Type 0x00000008 (8)
Framed-MTU 0x00000514 (1300)
Nas-Port-Type 0x00000013 (19)
Cisco / Audit-Session-Id 0150280a0000001b47f83c60
Acct-Session-Id 603cf847/00:11:22:33:44:55/35

(WLC1) >test aaa show radius

previous test command still not completed, try after some time

(WLC1) >test aaa show radius

Radius Test Request
Wlan-id........................................ 3
ApGroup Name................................... none
Radius Test Response

Radius Server Retry Status
------------- ----- ------
xx.xx.21.xx 6 No response received from server

Authentication Response:
Result Code: No response received from server
No AVPs in Response

-----

Thanks

[Sandeep Choudhary · Accepted solution]

Check if anything is blocking between ISE and WLC.

If nothing blocking then raise a TAC case or downgrade the Software of WLC and try again!

Regards

Dont forget to arte helpful posts

[ittechk4u1]

Thank you guys.

Finally issue got resolved after WLC/AP downgraded to 8.8.125.0 version.

Dont know why cisco have so bugy softwares.

Thanks again to all.

[Scott Fella · Accepted solution]

Like what Sandeep mentioned, looks like the connectivity for radius is being blocked or dropped. Here is a guide on the test to help clarify what the test commands do and how to read the output.

https://www.cisco.com/c/en/us/support/docs/wireless-mobility/wireless-lan-wlan/212473-verify-radius-server-connectivity-with-t.html

[Nicolas Poirier]

Are you seeing logs on the ISE RADIUS Livelogs?

First thing to check is if the Access-Request is received by your ISE Server.

If the request was dropped by the ISE Server, you will have an explaination on the log.

If the Request was not received, I would checked routing and filtering between WLC and ISE.

If you don't find any log on ISE, you can perform a tcpdump from the ISE Server (Operations > Diagnostic Tools > TCP Dump) to verify that the RADIUS request from the WLC is received by the ISE Server.