Security

 View Only
Back to discussions
Expand all | Collapse all

Error Code: 9002 RADIUS Client did not complete EAP transaction

This thread has been viewed 18 times

  • 1.  Error Code: 9002 RADIUS Client did not complete EAP transaction

    Posted Oct 04, 2023 06:43 AM

    Hi.

    I have two Radius Clearpass servers and huge number of timeouts:

    Error Code:
    9002
    Error Category:
    RADIUS protocol
    Error Message:
    Request timed out
     Alerts for this Request 
    RADIUS Client did not complete EAP transaction
    What could this be caused by?
    In logs we can see these errors:
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_eap_peap: Initiate
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 47:88:5414f3f79298:ANUAJACpADv73lcBX2eM/3+hlyXkHZieP0S9mg==
    2023-10-04 12:06:56,852 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "BX-802.1x-WBAP" - 49:440:5414f3f79298
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 49:1124:5414f3f79298:ACYAYwCxAAb83lcBd5xebnMGPKZ1CxS+eB99kA==
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R0013b27c-05-651d3940, state - ACYAYwCxAAb83lcBd5xebnMGPKZ1CxS+eB99kA=
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Packet 47:252:88:5414f3f79298 recv 1696414016.785892 - resp 1696414016.790918
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Packet 49:440:1124:5414f3f79298 recv 1696414016.851903 - resp 1696414016.853393
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
    2023-10-04 12:07:48,877 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 5414f3f79298
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3265 entity id = 29

    The whole logs are here:

    Request log details for session: R0013b27c-05-651d3940
    Time Message
    2023-10-04 12:06:56,786 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 47:252:5414f3f79298
    2023-10-04 12:06:56,788 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260660 h=223 r=R0013b27c-05-651d3940] INFO Core.ServiceReqHandler - Service classification result = BX-802.1x-WBAP
    2023-10-04 12:06:56,789 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - Service Categorization time = 3 ms
    2023-10-04 12:06:56,789 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "BX-802.1x-WBAP"
    2023-10-04 12:06:56,789 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_ldap: searching for user BBBBB-net\XXXXXXX in AD:corp.BBBBB.net
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_ldap: found user BBBBB-net\XXXXXXX in AD:corp.BBBBB.net
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - LDAP/AD User lookup time = 1 ms
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_eap_peap: Initiate
    2023-10-04 12:06:56,790 [Th 248 Req 22535931 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 47:88:5414f3f79298:ANUAJACpADv73lcBX2eM/3+hlyXkHZieP0S9mg==
    2023-10-04 12:06:56,852 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "BX-802.1x-WBAP" - 49:440:5414f3f79298
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client key exchange A
    2023-10-04 12:06:56,853 [Th 253 Req 22535932 SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 49:1124:5414f3f79298:ACYAYwCxAAb83lcBd5xebnMGPKZ1CxS+eB99kA==
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R0013b27c-05-651d3940, state - ACYAYwCxAAb83lcBd5xebnMGPKZ1CxS+eB99kA=
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Packet 47:252:88:5414f3f79298 recv 1696414016.785892 - resp 1696414016.790918
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] ERROR RadiusServer.Radius - reqst_clean_list: Packet 49:440:1124:5414f3f79298 recv 1696414016.851903 - resp 1696414016.853393
    2023-10-04 12:07:48,876 [main SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
    2023-10-04 12:07:48,877 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 5414f3f79298
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3265 entity id = 29
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3265
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3265|entityId=29
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3265|entity=Device
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser)
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=psauto-1690209519-4260800 h=239 r=R0013b27c-05-651d3940] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
    2023-10-04 12:07:48,878 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
    2023-10-04 12:07:48,879 [RequestHandler-1-0x7f19f29f4700 h=28372189 c=R0013b27c-05-651d3940] INFO Core.PETaskRoleMapping - Roles: BX-Role-AD-Lista-OU
    2023-10-04 12:07:48,879 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
    2023-10-04 12:07:48,879 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
    2023-10-04 12:07:48,880 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372191 c=R0013b27c-05-651d3940] ERROR Core.PETaskPolicyResult - handleHttpResponseEv: All policy result cache lookups failed
    2023-10-04 12:07:48,880 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
    2023-10-04 12:07:48,880 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 h=28372192 c=R0013b27c-05-651d3940] INFO Core.PETaskEnforcement - EnfProfiles: Enf-Prof-BX-IAP-Role-AD-OU
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 h=28372198 c=R0013b27c-05-651d3940] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 h=28372193 c=R0013b27c-05-651d3940] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 h=28372193 c=R0013b27c-05-651d3940] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Enf-Prof-BX-IAP-Role-AD-OU
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 h=28372193 c=R0013b27c-05-651d3940] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
    2023-10-04 12:07:48,881 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 h=28372199 c=R0013b27c-05-651d3940] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372197 c=R0013b27c-05-651d3940] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372194 c=R0013b27c-05-651d3940] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
    2023-10-04 12:07:48,882 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
    2023-10-04 12:07:48,885 [main SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - Policy Evaluation time = 9 ms
    2023-10-04 12:07:48,885 [main SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile
    2023-10-04 12:07:48,885 [main SessId R0013b27c-05-651d3940] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 h=28372201 c=R0013b27c-05-651d3940] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 h=28372201 c=R0013b27c-05-651d3940] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 h=28372200 c=R0013b27c-05-651d3940] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
    2023-10-04 12:07:48,885 [RequestHandler-1-0x7f19f29f4700 r=R0013b27c-05-651d3940 h=28372187 c=R0013b27c-05-651d3940] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***


  • 2.  RE: Error Code: 9002 RADIUS Client did not complete EAP transaction

    Posted Oct 04, 2023 10:37 AM

    Hi

    This error message often indicates a faulty configuration on the client side. How do you configure the client, is it manual or a GPO or another management tool?

    Does the problem affect one client or all clients?

    This error is also common after changing the Radius certificate and you have Apple devices like iPhones and iPads. IOS devices will prompt the user to accept the new Radius certificate. Until the user have accepted the new certificate the device will time out in Access Tracker.



    ------------------------------
    Best Regards
    Jonas Hammarbäck
    MVP 2023, ACCX #1335, ACX-Network Security, Aruba SME, ACMP, ACDP , ACEP, ACSA
    Aranya AB
    If you find my answer useful, consider giving kudos and/or mark as solution
    ------------------------------

    Original Message


Related Content