Security

 View Only
last person joined: yesterday 

Enterprise security using ClearPass Policy Management, ClearPass Security Exchange, IntroSpect, VIA, 360 Security Exchange, Extensions and Policy Enforcement Firewall (PEF).
Expand all | Collapse all

Client did not complete EAP transaction

This thread has been viewed 21 times
  • 1.  Client did not complete EAP transaction

    Posted Jun 13, 2022 04:55 AM
    Hi Teams,
    We are experiencing an authentication timeout issue. A small number of clients cannot complete the EAP transaction, and the authentication method we use is EAP-PEAP. Do you have any suggestions?


    Request log details for session: R000001da-01-62a6f982

    Time Message
    2022-06-13 16:46:58,305 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,305 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 210:309:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,309 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1375 h=931 r=R000001da-01-62a6f982] INFO Core.ServiceReqHandler - Service classification result = MPS_Wired_AD_User_Login
    2022-06-13 16:46:58,310 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - Service Categorization time = 5 ms
    2022-06-13 16:46:58,310 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "MPS_Wired_AD_User_Login"
    2022-06-13 16:46:58,310 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_ldap: searching for user MONOLITHICPOWER\hevhe in AD:cd-ds02.monolithicpower.com
    2022-06-13 16:46:58,312 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_ldap: found user MONOLITHICPOWER\hevhe in AD:cd-ds02.monolithicpower.com
    2022-06-13 16:46:58,312 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - LDAP/AD User lookup time = 2 ms
    2022-06-13 16:46:58,312 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_eap_peap: Initiate
    2022-06-13 16:46:58,313 [Th 204 Req 2500 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 210:88:00-2B-67-E1-C7-BC:AIYA2wDLAArECQAAcwyg/hGHOmzxYPSy14ukTg==
    2022-06-13 16:46:58,319 [Th 202 Req 2501 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,319 [Th 202 Req 2501 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MPS_Wired_AD_User_Login" - 211:497:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,321 [Th 202 Req 2501 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2022-06-13 16:46:58,321 [Th 202 Req 2501 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2022-06-13 16:46:58,322 [Th 202 Req 2501 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 211:1124:00-2B-67-E1-C7-BC:AIgASACwAKTFCQAAp51CHF/v3WUcruTTpZ7epw==
    2022-06-13 16:46:58,326 [Th 203 Req 2502 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,326 [Th 203 Req 2502 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MPS_Wired_AD_User_Login" - 212:331:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,327 [Th 203 Req 2502 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 212:1120:00-2B-67-E1-C7-BC:AGcAcwC1ABrGCQAAjCQNvijFhuPBoyDke+MOOw==
    2022-06-13 16:46:58,332 [Th 201 Req 2503 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,332 [Th 201 Req 2503 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MPS_Wired_AD_User_Login" - 213:331:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,333 [Th 201 Req 2503 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 213:1120:00-2B-67-E1-C7-BC:AAMAQgBzAGDHCQAAIATXQwS2gbjrTN0pFUIYzQ==
    2022-06-13 16:46:58,337 [Th 204 Req 2504 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,337 [Th 204 Req 2504 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MPS_Wired_AD_User_Login" - 214:331:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,338 [Th 204 Req 2504 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 214:801:00-2B-67-E1-C7-BC:AH0AcABOAJTICQAAvF2ah5gLYh+gDtNg45LjQA==
    2022-06-13 16:46:58,345 [Th 202 Req 2505 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: device-public-mac= value not present in any of Cisco-AVPairs
    2022-06-13 16:46:58,345 [Th 202 Req 2505 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "MPS_Wired_AD_User_Login" - 215:461:00-2B-67-E1-C7-BC
    2022-06-13 16:46:58,346 [Th 202 Req 2505 SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 215:139:00-2B-67-E1-C7-BC:AAgAxgAqAPnJCQAAFbQ5JM3s9ecv1mpC5R9DoA==
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R000001da-01-62a6f982, state - AAgAxgAqAPnJCQAAFbQ5JM3s9ecv1mpC5R9DoA=
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 210:309:88:00-2B-67-E1-C7-BC recv 1655110018.305127 - resp 1655110018.313392
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 211:497:1124:00-2B-67-E1-C7-BC recv 1655110018.319209 - resp 1655110018.322060
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 212:331:1120:00-2B-67-E1-C7-BC recv 1655110018.325877 - resp 1655110018.327446
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 213:331:1120:00-2B-67-E1-C7-BC recv 1655110018.331495 - resp 1655110018.333128
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 214:331:801:00-2B-67-E1-C7-BC recv 1655110018.337123 - resp 1655110018.338705
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] ERROR RadiusServer.Radius - reqst_clean_list: Packet 215:461:139:00-2B-67-E1-C7-BC recv 1655110018.345156 - resp 1655110018.346486
    2022-06-13 16:47:45,348 [main SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 002b67e1c7bc
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3061 entity id = 29
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3061
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3061|entityId=29
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3061|entity=Device
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser)
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 r=psauto-1655078261-1376 h=1081 r=R000001da-01-62a6f982] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
    2022-06-13 16:47:45,351 [RequestHandler-1-0x7fb68bcc6700 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
    2022-06-13 16:47:45,352 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
    2022-06-13 16:47:45,353 [RequestHandler-1-0x7fb68bcc6700 h=12154 c=R000001da-01-62a6f982] INFO Core.PETaskRoleMapping - Roles: AD_Computer
    2022-06-13 16:47:45,353 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
    2022-06-13 16:47:45,353 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
    2022-06-13 16:47:45,359 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12156 c=R000001da-01-62a6f982] ERROR Core.PETaskPolicyResult - handleHttpResponseEv: All policy result cache lookups failed
    2022-06-13 16:47:45,359 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
    2022-06-13 16:47:45,359 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
    2022-06-13 16:47:45,360 [RequestHandler-1-0x7fb68bcc6700 h=12157 c=R000001da-01-62a6f982] INFO Core.PETaskEnforcement - EnfProfiles: dACL_For_Quarantine
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 h=12163 c=R000001da-01-62a6f982] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 h=12158 c=R000001da-01-62a6f982] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 h=12158 c=R000001da-01-62a6f982] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: dACL_For_Quarantine
    2022-06-13 16:47:45,361 [RequestHandler-1-0x7fb68bcc6700 h=12158 c=R000001da-01-62a6f982] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 h=12164 c=R000001da-01-62a6f982] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12159 c=R000001da-01-62a6f982] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device
    2022-06-13 16:47:45,362 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
    2022-06-13 16:47:45,366 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12162 c=R000001da-01-62a6f982] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device
    2022-06-13 16:47:45,367 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
    2022-06-13 16:47:45,367 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
    2022-06-13 16:47:45,367 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
    2022-06-13 16:47:45,367 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
    2022-06-13 16:47:45,371 [RequestHandler-1-0x7fb68bcc6700 h=12166 c=R000001da-01-62a6f982] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
    2022-06-13 16:47:45,371 [RequestHandler-1-0x7fb68bcc6700 h=12166 c=R000001da-01-62a6f982] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
    2022-06-13 16:47:45,371 [RequestHandler-1-0x7fb68bcc6700 h=12165 c=R000001da-01-62a6f982] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
    2022-06-13 16:47:45,372 [main SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - Policy Evaluation time = 24 ms
    2022-06-13 16:47:45,372 [main SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile
    2022-06-13 16:47:45,372 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
    2022-06-13 16:47:45,372 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
    2022-06-13 16:47:45,372 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
    2022-06-13 16:47:45,372 [RequestHandler-1-0x7fb68bcc6700 r=R000001da-01-62a6f982 h=12152 c=R000001da-01-62a6f982] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***
    2022-06-13 16:47:45,373 [main SessId R000001da-01-62a6f982] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response


  • 2.  RE: Client did not complete EAP transaction

    Posted Jun 16, 2022 10:58 AM
    we are having something happen very similar, some clients are not able to authenticate... usually right when they come in for the day.... if they unplug their network cable then plug back in they seem to be able to get a connection and are able to log on.  other older forum posts i have found stated that it might be a cert issue?  we are still looking it this as well.