Time | Message |
2016-12-01 16:26:02,267 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 207:199:b01041ca594b |
2016-12-01 16:26:02,270 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2294 h=223 r=R00000343-01-5840956a] INFO Core.ServiceReqHandler - Service classification result = Copy_of_AYNI-Cert Onboard Provisioning |
2016-12-01 16:26:02,271 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - Service Categorization time = 4 ms |
2016-12-01 16:26:02,271 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" |
2016-12-01 16:26:02,271 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_ldap: searching for user usrWL.test in AD:DCSIS11.sunat.peru |
2016-12-01 16:26:02,373 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_ldap: found user usrWL.test in AD:DCSIS11.sunat.peru |
2016-12-01 16:26:02,373 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - LDAP/AD User lookup time = 102 ms |
2016-12-01 16:26:02,373 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_eap_tls: Initiate |
2016-12-01 16:26:02,373 | [Th 38 Req 7400 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 207:88:b01041ca594b:AHEAewCXALfoHAAAjLuZMt/olSMiM+VW4lXWdA== |
2016-12-01 16:26:02,467 | [Th 40 Req 7401 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 208:408:b01041ca594b |
2016-12-01 16:26:02,473 | [Th 40 Req 7401 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A |
2016-12-01 16:26:02,473 | [Th 40 Req 7401 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A |
2016-12-01 16:26:02,474 | [Th 40 Req 7401 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 208:1124:b01041ca594b:ANUAMAAiAIXpHAAApocodm12HQgpT1FN47jKnw== |
2016-12-01 16:26:02,541 | [Th 33 Req 7402 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 209:232:b01041ca594b |
2016-12-01 16:26:02,541 | [Th 33 Req 7402 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 209:1120:b01041ca594b:AJoA6wANAJ/qHAAAdeRePCChz3djAao7OX2mtA== |
2016-12-01 16:26:02,591 | [Th 34 Req 7403 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 210:232:b01041ca594b |
2016-12-01 16:26:02,591 | [Th 34 Req 7403 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 210:1120:b01041ca594b:AAMAvgB+ADHrHAAAhoGba5Fu+0bIf6gxj88Udg== |
2016-12-01 16:26:02,655 | [Th 35 Req 7404 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 211:232:b01041ca594b |
2016-12-01 16:26:02,656 | [Th 35 Req 7404 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 211:1120:b01041ca594b:AIAACAD2AJ7sHAAAYLIEK+H2FOahopmJicEJ0w== |
2016-12-01 16:26:02,711 | [Th 36 Req 7405 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 212:232:b01041ca594b |
2016-12-01 16:26:02,712 | [Th 36 Req 7405 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 212:1120:b01041ca594b:AIIA+QC9ALHtHAAA2L3XTyM8Oll4lYqkErtt7Q== |
2016-12-01 16:26:02,776 | [Th 37 Req 7406 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 213:232:b01041ca594b |
2016-12-01 16:26:02,777 | [Th 37 Req 7406 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 213:1120:b01041ca594b:ADkAsQAuAG3uHAAAok68+8kku0AIUMgPh6O9og== |
2016-12-01 16:26:02,853 | [Th 39 Req 7407 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 214:232:b01041ca594b |
2016-12-01 16:26:02,853 | [Th 39 Req 7407 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 214:1120:b01041ca594b:AOUA1QDdAEvvHAAAAB2FeVGsHO3IyOGw8BFU8Q== |
2016-12-01 16:26:02,925 | [Th 38 Req 7408 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 215:232:b01041ca594b |
2016-12-01 16:26:02,925 | [Th 38 Req 7408 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 215:506:b01041ca594b:ABMAUQDCAIrwHAAARj4B7evK0pxsT1hqnWwaDQ== |
2016-12-01 16:26:03,262 | [Th 40 Req 7409 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 216:1728:b01041ca594b |
2016-12-01 16:26:03,262 | [Th 40 Req 7409 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 216:88:b01041ca594b:ACwAcQAWAKjxHAAAnmxkwlC2f+SHL+zTqCwWow== |
2016-12-01 16:26:03,327 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "Copy_of_AYNI-Cert Onboard Provisioning" - 217:1430:b01041ca594b |
2016-12-01 16:26:03,367 | [Th 33 Req 7410 SessId R00000343-01-5840956a] WARN RadiusServer.Radius - Error: Couldn't verify OCSP basic response, status 0, trying with OCSP_NOCHECKS |
2016-12-01 16:26:03,367 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - ocsp] --> Cert status: unknown |
2016-12-01 16:26:03,367 | [Th 33 Req 7410 SessId R00000343-01-5840956a] ERROR RadiusServer.Radius - ocsp] --> Reason: (UNKNOWN) |
2016-12-01 16:26:03,367 | [Th 33 Req 7410 SessId R00000343-01-5840956a] ERROR RadiusServer.Radius - OCSP checks have failed |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - chain-depth=0, |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - error=0 |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - --> User-Name = usrWL.test |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - --> subject = /C=PE/ST=LIMA/L=LIMA/O=SUNAT/CN=usrWL.test/emailAddress=usrWL.test@sunat.gob.pe |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - --> issuer = /C=PE/ST=LIMA/L=LIMA/O=SUNAT/CN=SUNAT ClearPass Onboard Local Certificate Authority (Signing)/emailAddress=sunat@sunat.gob.pe |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - --> verify return:0 |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] ERROR RadiusServer.Radius - TLS Alert write:fatal:certificate unknown |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - TLS_accept:error in error |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] ERROR RadiusServer.Radius - rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails. error:14089086:SSL routines:ssl3_get_client_certificate:certificate verify failed |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] ERROR RadiusServer.Radius - rlm_eap_tls: TLS Handshake failed |
2016-12-01 16:26:03,368 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr b01041ca594b |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3002 entity id = 29 |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3002 |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3002|entityId=29 |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3002|entity=Device |
2016-12-01 16:26:03,373 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
2016-12-01 16:26:03,374 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
2016-12-01 16:26:03,374 | [RequestHandler-1-0x7f28fd3e9700 r=psauto-1480111576-2295 h=239 r=R00000343-01-5840956a] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
2016-12-01 16:26:03,374 | [RequestHandler-1-0x7f28fd3e9700 h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
2016-12-01 16:26:03,374 | [RequestHandler-1-0x7f28fd3e9700 h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
2016-12-01 16:26:03,374 | [RequestHandler-1-0x7f28fd3e9700 h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
2016-12-01 16:26:03,375 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
2016-12-01 16:26:03,375 | [RequestHandler-1-0x7f28fd3e9700 h=17411 c=R00000343-01-5840956a] INFO Core.PETaskRoleMapping - Roles: |
2016-12-01 16:26:03,376 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
2016-12-01 16:26:03,376 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
2016-12-01 16:26:03,377 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
2016-12-01 16:26:03,377 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
2016-12-01 16:26:03,378 | [RequestHandler-1-0x7f28fd3e9700 h=17414 c=R00000343-01-5840956a] INFO Core.PETaskEnforcement - EnfProfiles: Allow Access Profile], AYNI-Cert Onboard Post-Provisioning |
2016-12-01 16:26:03,378 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
2016-12-01 16:26:03,379 | [RequestHandler-1-0x7f28fd3e9700 h=17419 c=R00000343-01-5840956a] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
2016-12-01 16:26:03,380 | [RequestHandler-1-0x7f28fd3e9700 h=17415 c=R00000343-01-5840956a] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
2016-12-01 16:26:03,380 | [RequestHandler-1-0x7f28fd3e9700 h=17415 c=R00000343-01-5840956a] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Allow Access Profile], AYNI-Cert Onboard Post-Provisioning |
2016-12-01 16:26:03,380 | [RequestHandler-1-0x7f28fd3e9700 h=17415 c=R00000343-01-5840956a] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 h=17420 c=R00000343-01-5840956a] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17418 c=R00000343-01-5840956a] WARN Core.PETaskPostAuthEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg= |
2016-12-01 16:26:03,381 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17418 c=R00000343-01-5840956a] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17416 c=R00000343-01-5840956a] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
2016-12-01 16:26:03,382 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
2016-12-01 16:26:03,389 | [RequestHandler-1-0x7f28fd3e9700 h=17422 c=R00000343-01-5840956a] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
2016-12-01 16:26:03,389 | [RequestHandler-1-0x7f28fd3e9700 h=17422 c=R00000343-01-5840956a] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
2016-12-01 16:26:03,390 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - Policy Evaluation time = 21 ms |
2016-12-01 16:26:03,390 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
2016-12-01 16:26:03,390 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
2016-12-01 16:26:03,390 | [RequestHandler-1-0x7f28fd3e9700 h=17421 c=R00000343-01-5840956a] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
2016-12-01 16:26:03,390 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
2016-12-01 16:26:03,390 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
2016-12-01 16:26:03,390 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
2016-12-01 16:26:03,390 | [RequestHandler-1-0x7f28fd3e9700 r=R00000343-01-5840956a h=17409 c=R00000343-01-5840956a] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |
2016-12-01 16:26:03,391 | [Th 33 Req 7410 SessId R00000343-01-5840956a] INFO RadiusServer.Radius - Request processing time = 1123 ms |