| Time | Message |
|---|---|
| 2018-02-23 15:47:30,549 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 19:202:d4-be-d9-6d-ce-74 |
| 2018-02-23 15:47:30,554 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1095 h=223 r=R000001ea-01-5a901b72] INFO Core.ServiceReqHandler - Service classification result = LITGRID |
| 2018-02-23 15:47:30,555 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - Service Categorization time = 6 ms |
| 2018-02-23 15:47:30,555 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "LITGRID" |
| 2018-02-23 15:47:30,555 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_sql: searching for user d4bed96dce74 in Local:localhost |
| 2018-02-23 15:47:30,564 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_sql: found user d4bed96dce74 in Local:localhost |
| 2018-02-23 15:47:30,565 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - SQL User lookup time = 10 ms |
| 2018-02-23 15:47:30,565 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr d4bed96dce74 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.AuthLocalUserTable - Returning AuthLocalUserSPtr for user ID d4bed96dce74 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3001 entity id = 29 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3001 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3001|entityId=29 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3001|entity=Device |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3003 entity id = 30 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for AuthLocalUser instance=3003 |
| 2018-02-23 15:47:30,568 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for instanceId=3003|entityId=30|entityName=AuthLocalUsers |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3003|entity=LocalUser |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 r=psauto-1519029487-1096 h=239 r=R000001ea-01-5a901b72] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2018-02-23 15:47:30,569 | [RequestHandler-1-0x7f0d147e3700 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2018-02-23 15:47:30,570 | [RequestHandler-1-0x7f0d147e3700 h=9669 c=R000001ea-01-5a901b72] WARN REC.EvaluatorCtx - Prerequisites set is empty, not populating the Request Map |
| 2018-02-23 15:47:30,570 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2018-02-23 15:47:30,570 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9670 c=R000001ea-01-5a901b72] INFO Common.AuthLocalUserTable - Returning AuthLocalUserSPtr for user ID d4bed96dce74 |
| 2018-02-23 15:47:30,571 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9670 c=R000001ea-01-5a901b72] INFO Core.PETaskRoleMapping - Roles: Employee], Machine Authenticated], User Authenticated] |
| 2018-02-23 15:47:30,571 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2018-02-23 15:47:30,571 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2018-02-23 15:47:30,571 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2018-02-23 15:47:30,571 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2018-02-23 15:47:30,572 | [RequestHandler-1-0x7f0d147e3700 h=9673 c=R000001ea-01-5a901b72] INFO Core.PETaskEnforcement - EnfProfiles: Litgrid3 802.1X Wireless Initial Profile |
| 2018-02-23 15:47:30,573 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2018-02-23 15:47:30,573 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2018-02-23 15:47:30,573 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-02-23 15:47:30,573 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2018-02-23 15:47:30,573 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder ** |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 h=9679 c=R000001ea-01-5a901b72] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 h=9674 c=R000001ea-01-5a901b72] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 h=9674 c=R000001ea-01-5a901b72] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Litgrid3 802.1X Wireless Initial Profile |
| 2018-02-23 15:47:30,574 | [RequestHandler-1-0x7f0d147e3700 h=9674 c=R000001ea-01-5a901b72] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 10800 |
| 2018-02-23 15:47:30,575 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2018-02-23 15:47:30,575 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder ** |
| 2018-02-23 15:47:30,575 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2018-02-23 15:47:30,575 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2018-02-23 15:47:30,575 | [RequestHandler-1-0x7f0d147e3700 h=9680 c=R000001ea-01-5a901b72] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9678 c=R000001ea-01-5a901b72] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9675 c=R000001ea-01-5a901b72] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2018-02-23 15:47:30,576 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskMacAuthResetHandler ** |
| 2018-02-23 15:47:30,577 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2018-02-23 15:47:30,577 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2018-02-23 15:47:30,581 | [RequestHandler-1-0x7f0d147e3700 h=9683 c=R000001ea-01-5a901b72] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2018-02-23 15:47:30,582 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - Policy Evaluation time = 17 ms |
| 2018-02-23 15:47:30,582 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
| 2018-02-23 15:47:30,582 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_policy: Added Class attribute with value Class = 0x6a6df5933869450fa789eeac43525e73b90b0000000000005230303030303165612d30312d35613930316237320000000000000000000000 |
| 2018-02-23 15:47:30,582 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2018-02-23 15:47:30,582 | [RequestHandler-1-0x7f0d147e3700 h=9683 c=R000001ea-01-5a901b72] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-02-23 15:47:30,583 | [Th 43 Req 1747 SessId R000001ea-01-5a901b72] INFO RadiusServer.Radius - Request processing time = 33 ms |
| 2018-02-23 15:47:30,597 | [RequestHandler-1-0x7f0d147e3700 h=9681 c=R000001ea-01-5a901b72] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-02-23 15:47:30,598 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2018-02-23 15:47:30,598 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2018-02-23 15:47:30,598 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2018-02-23 15:47:30,599 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9685] ERROR Core.MacAuthSessionQueryEventHandler - Failed to get MacAuth session info for d4bed96dce74 |
| 2018-02-23 15:47:30,599 | [RequestHandler-1-0x7f0d147e3700 h=9682 c=R000001ea-01-5a901b72] WARN Core.PETaskMacAuthResetHandler - handleMacAuthSessionResponseEv: Error reading MacAuth session info. Error=Failed to get MacAuth session info for d4bed96dce74 |
| 2018-02-23 15:47:30,599 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - ** Completed PETaskMacAuthResetHandler ** |
| 2018-02-23 15:47:30,599 | [RequestHandler-1-0x7f0d147e3700 r=R000001ea-01-5a901b72 h=9668 c=R000001ea-01-5a901b72] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |