| Time | Message |
|---|---|
| 2018-01-12 12:25:18,203 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 204:183:7C04D0BF2C0A |
| 2018-01-12 12:25:18,212 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833370 h=223 r=R009803da-02-5a5838ae] INFO Core.ServiceReqHandler - Service classification result = Yum-TLS |
| 2018-01-12 12:25:18,213 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - Service Categorization time = 10 ms |
| 2018-01-12 12:25:18,214 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "Yum-TLS" |
| 2018-01-12 12:25:18,214 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_ldap: searching for user cxx7580 in AD:172.31.88.15 |
| 2018-01-12 12:25:18,226 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_ldap: found user cxx7580 in AD:172.31.88.15 |
| 2018-01-12 12:25:18,227 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - LDAP/AD User lookup time = 12 ms |
| 2018-01-12 12:25:18,227 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_eap_peap: Initiate |
| 2018-01-12 12:25:18,233 | [Th 1985 Req 20872820 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 204:88:7C04D0BF2C0A:ABUAEwARADB0fj4BhoDfA1AnvRjcvo+0m422Ig== |
| 2018-01-12 12:25:18,248 | [Th 1984 Req 20872821 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 203:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,248 | [Th 1984 Req 20872821 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_eap_tls: Initiate |
| 2018-01-12 12:25:18,256 | [Th 1984 Req 20872821 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 203:88:7C04D0BF2C0A:APAAJwAfAId1fj4BmfZrksB9APAmhh0aevU0KQ== |
| 2018-01-12 12:25:18,278 | [Th 1978 Req 20872822 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 197:340:7C04D0BF2C0A |
| 2018-01-12 12:25:18,285 | [Th 1978 Req 20872822 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A |
| 2018-01-12 12:25:18,293 | [Th 1978 Req 20872822 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 197:1124:7C04D0BF2C0A:ALsAwAAMABN2fj4BNdmi5xz3RDDvPZyzu4OKWw== |
| 2018-01-12 12:25:18,307 | [Th 1980 Req 20872823 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 202:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,315 | [Th 1980 Req 20872823 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 202:1120:7C04D0BF2C0A:AK8AmACvAL93fj4BakiY/8F2XQIz716QxlWQYg== |
| 2018-01-12 12:25:18,329 | [Th 1979 Req 20872824 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 206:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,337 | [Th 1979 Req 20872824 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 206:1120:7C04D0BF2C0A:ABIAaABRAJF4fj4Bo/95C+8dHWt9HWcB4EVqEA== |
| 2018-01-12 12:25:18,351 | [Th 1986 Req 20872825 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 205:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,359 | [Th 1986 Req 20872825 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 205:1120:7C04D0BF2C0A:AC8ARgDUACB5fj4BaXJtVA0foYEAunhPUMho/A== |
| 2018-01-12 12:25:18,375 | [Th 1977 Req 20872826 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 200:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,384 | [Th 1977 Req 20872826 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 200:1120:7C04D0BF2C0A:AMIA9QAaADJ6fj4B9Jz7hycFTRk3KXGe4M0Gsw== |
| 2018-01-12 12:25:18,400 | [Th 1983 Req 20872827 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 189:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,409 | [Th 1983 Req 20872827 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 189:1120:7C04D0BF2C0A:ADsAmAD+AAF7fj4B69Eu9D5JyMBgeQFCtcOwyg== |
| 2018-01-12 12:25:18,423 | [Th 1981 Req 20872828 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 215:219:7C04D0BF2C0A |
| 2018-01-12 12:25:18,432 | [Th 1981 Req 20872828 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 215:380:7C04D0BF2C0A:AN0AOQCjANl8fj4BXCXYY473Hliwj3zS7H2CQg== |
| 2018-01-12 12:25:18,460 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Yum-TLS" - 183:230:7C04D0BF2C0A |
| 2018-01-12 12:25:18,460 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] ERROR RadiusServer.Radius - TLS Alert read:warning:close notify |
| 2018-01-12 12:25:18,460 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] ERROR RadiusServer.Radius - TLS_accept:failed in SSLv3 read client certificate A |
| 2018-01-12 12:25:18,460 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] ERROR RadiusServer.Radius - rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails. error:140940E5:SSL routines:SSL3_READ_BYTES:ssl handshake failure |
| 2018-01-12 12:25:18,460 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] ERROR RadiusServer.Radius - rlm_eap_tls: TLS Handshake failed |
| 2018-01-12 12:25:18,461 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2018-01-12 12:25:18,476 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 7c04d0bf2c0a |
| 2018-01-12 12:25:18,476 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3003 entity id = 29 |
| 2018-01-12 12:25:18,476 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3003 |
| 2018-01-12 12:25:18,476 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3003|entityId=29 |
| 2018-01-12 12:25:18,476 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3003|entity=Device |
| 2018-01-12 12:25:18,477 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
| 2018-01-12 12:25:18,477 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2018-01-12 12:25:18,477 | [RequestHandler-1-0x7ffb96ff7700 r=psauto-1485325197-22833371 h=239 r=R009803da-02-5a5838ae] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2018-01-12 12:25:18,478 | [RequestHandler-1-0x7ffb96ff7700 h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2018-01-12 12:25:18,478 | [RequestHandler-1-0x7ffb96ff7700 h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2018-01-12 12:25:18,478 | [RequestHandler-1-0x7ffb96ff7700 h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2018-01-12 12:25:18,480 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2018-01-12 12:25:18,480 | [RequestHandler-1-0x7ffb96ff7700 h=205725990 c=R009803da-02-5a5838ae] INFO Core.PETaskRoleMapping - Roles: |
| 2018-01-12 12:25:18,481 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2018-01-12 12:25:18,481 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2018-01-12 12:25:18,482 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2018-01-12 12:25:18,483 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2018-01-12 12:25:18,485 | [RequestHandler-1-0x7ffb96ff7700 h=205725993 c=R009803da-02-5a5838ae] INFO Core.PETaskEnforcement - EnfProfiles: Allow Access Profile] |
| 2018-01-12 12:25:18,486 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2018-01-12 12:25:18,486 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2018-01-12 12:25:18,486 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-01-12 12:25:18,487 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2018-01-12 12:25:18,487 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2018-01-12 12:25:18,487 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2018-01-12 12:25:18,487 | [RequestHandler-1-0x7ffb96ff7700 h=205725998 c=R009803da-02-5a5838ae] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2018-01-12 12:25:18,489 | [RequestHandler-1-0x7ffb96ff7700 h=205725994 c=R009803da-02-5a5838ae] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
| 2018-01-12 12:25:18,489 | [RequestHandler-1-0x7ffb96ff7700 h=205725994 c=R009803da-02-5a5838ae] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Allow Access Profile] |
| 2018-01-12 12:25:18,490 | [RequestHandler-1-0x7ffb96ff7700 h=205725994 c=R009803da-02-5a5838ae] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 |
| 2018-01-12 12:25:18,490 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2018-01-12 12:25:18,490 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2018-01-12 12:25:18,491 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2018-01-12 12:25:18,491 | [RequestHandler-1-0x7ffb96ff7700 h=205725999 c=R009803da-02-5a5838ae] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
| 2018-01-12 12:25:18,491 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2018-01-12 12:25:18,492 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725997 c=R009803da-02-5a5838ae] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2018-01-12 12:25:18,492 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2018-01-12 12:25:18,492 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2018-01-12 12:25:18,493 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725995 c=R009803da-02-5a5838ae] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
| 2018-01-12 12:25:18,493 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-01-12 12:25:18,493 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2018-01-12 12:25:18,493 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2018-01-12 12:25:18,493 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2018-01-12 12:25:18,501 | [RequestHandler-1-0x7ffb96ff7700 h=205726001 c=R009803da-02-5a5838ae] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2018-01-12 12:25:18,501 | [RequestHandler-1-0x7ffb96ff7700 h=205726001 c=R009803da-02-5a5838ae] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-01-12 12:25:18,503 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - Policy Evaluation time = 32 ms |
| 2018-01-12 12:25:18,503 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
| 2018-01-12 12:25:18,503 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2018-01-12 12:25:18,503 | [RequestHandler-1-0x7ffb96ff7700 h=205726000 c=R009803da-02-5a5838ae] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-01-12 12:25:18,504 | [Th 1982 Req 20872829 SessId R009803da-02-5a5838ae] INFO RadiusServer.Radius - Request processing time = 301 ms |
| 2018-01-12 12:25:18,504 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2018-01-12 12:25:18,504 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2018-01-12 12:25:18,504 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2018-01-12 12:25:18,504 | [RequestHandler-1-0x7ffb96ff7700 r=R009803da-02-5a5838ae h=205725988 c=R009803da-02-5a5838ae] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |