| Time | Message |
|---|---|
| 2016-07-27 14:19:32,917 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 150:206:78-AC-C0-50-63-6E |
| 2016-07-27 14:19:33,035 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - Service Categorization time = 112 ms |
| 2016-07-27 14:19:33,035 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-388 h=79 r=R00000066-14-579898c4] INFO Core.ServiceReqHandler - Service classification result = Cisco-Wired MAC Auth (D13) |
| 2016-07-27 14:19:33,036 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "Cisco-Wired MAC Auth (D13)" |
| 2016-07-27 14:19:33,052 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_sql: searching for user 78acc050636e in Local:localhost |
| 2016-07-27 14:19:33,109 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2016-07-27 14:19:33,110 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_policy: Request does not have Authentication-Source-Name attribute |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 78acc050636e |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3026 entity id = 29 |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3026 |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3026|entityId=29 |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3026|entity=Device |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - No TagDefCacheMap could be found for instance id = 3327 entity id = 72 |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for Endpoint instance=3327 |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for instanceId=3327|entityId=72|entityName=Endpoint |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3327|entity=Endpoint |
| 2016-07-27 14:19:33,114 | [RequestHandler-1-0x7f3b6176a700 r=psauto-1469024463-389 h=83 r=R00000066-14-579898c4] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2016-07-27 14:19:33,115 | [RequestHandler-1-0x7f3b6176a700 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2016-07-27 14:19:33,115 | [RequestHandler-1-0x7f3b6176a700 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2016-07-27 14:19:33,115 | [RequestHandler-1-0x7f3b6176a700 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2016-07-27 14:19:33,116 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2016-07-27 14:19:33,126 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2687 c=R00000066-14-579898c4] INFO Core.PETaskRoleMapping - Roles: User Authenticated] |
| 2016-07-27 14:19:33,126 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2016-07-27 14:19:33,126 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2016-07-27 14:19:33,130 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2689 c=R00000066-14-579898c4] ERROR Core.PETaskPolicyResult - handleHttpResponseEv: All policy result cache lookups failed |
| 2016-07-27 14:19:33,130 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2016-07-27 14:19:33,130 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2016-07-27 14:19:33,150 | [AuthReqThreadPool-2-0x7f3b90f84700 r=R00000066-14-579898c4 h=26] ERROR ExtDB.DBQuery - ResultSet is empty |
| 2016-07-27 14:19:33,150 | [AuthReqThreadPool-2-0x7f3b90f84700 r=R00000066-14-579898c4 h=26] ERROR ExtDB.DBQuery - Failed to get value for attributes=Category] |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 h=2690 c=R00000066-14-579898c4] INFO Core.PETaskEnforcement - EnfProfiles: Cisco VLAN 200 Guest |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2016-07-27 14:19:33,163 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2016-07-27 14:19:33,164 | [RequestHandler-1-0x7f3b6176a700 h=2696 c=R00000066-14-579898c4] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2016-07-27 14:19:33,165 | [RequestHandler-1-0x7f3b6176a700 h=2692 c=R00000066-14-579898c4] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
| 2016-07-27 14:19:33,165 | [RequestHandler-1-0x7f3b6176a700 h=2692 c=R00000066-14-579898c4] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Cisco VLAN 200 Guest |
| 2016-07-27 14:19:33,165 | [RequestHandler-1-0x7f3b6176a700 h=2692 c=R00000066-14-579898c4] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 10800 |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 h=2697 c=R00000066-14-579898c4] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2693 c=R00000066-14-579898c4] WARN Core.PETaskRadiusCoAEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg= |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2695 c=R00000066-14-579898c4] WARN Core.PETaskPostAuthEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg= |
| 2016-07-27 14:19:33,166 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2695 c=R00000066-14-579898c4] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2016-07-27 14:19:33,167 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2016-07-27 14:19:33,167 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2016-07-27 14:19:33,167 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2016-07-27 14:19:33,226 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskMacAuthResetHandler ** |
| 2016-07-27 14:19:33,226 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2016-07-27 14:19:33,226 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2016-07-27 14:19:33,231 | [RequestHandler-1-0x7f3b6176a700 h=2700 c=R00000066-14-579898c4] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2016-07-27 14:19:33,231 | [RequestHandler-1-0x7f3b6176a700 h=2700 c=R00000066-14-579898c4] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2016-07-27 14:19:33,232 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - Policy Evaluation time = 122 ms |
| 2016-07-27 14:19:33,232 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
| 2016-07-27 14:19:33,232 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_policy: Added Class attribute with value Class = 0xbcf5d67000594b68830675e1dd8884abd40b0000000000005230303030303036362d31342d35373938393863340000000000000000000000 |
| 2016-07-27 14:19:33,232 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2016-07-27 14:19:33,232 | [Th 6 Req 311 SessId R00000066-14-579898c4] INFO RadiusServer.Radius - Request processing time = 337 ms |
| 2016-07-27 14:19:33,233 | [RequestHandler-1-0x7f3b6176a700 h=2698 c=R00000066-14-579898c4] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2702] ERROR Core.MacAuthSessionQueryEventHandler - Failed to get MacAuth session info for 78acc050636e |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 h=2699 c=R00000066-14-579898c4] WARN Core.PETaskMacAuthResetHandler - handleMacAuthSessionResponseEv: Error reading MacAuth session info. Error=Failed to get MacAuth session info for 78acc050636e |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - ** Completed PETaskMacAuthResetHandler ** |
| 2016-07-27 14:19:33,234 | [RequestHandler-1-0x7f3b6176a700 r=R00000066-14-579898c4 h=2685 c=R00000066-14-579898c4] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |