| Time | Message |
|---|---|
| 2018-03-27 17:50:23,841 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 23:198:f0d7aae6e917 |
| 2018-03-27 17:50:23,844 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-90 h=127 r=R0000002a-01-5abaae8f] INFO Core.ServiceReqHandler - Service classification result = TESTE_NPS_ARP |
| 2018-03-27 17:50:23,845 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - Service Categorization time = 3 ms |
| 2018-03-27 17:50:23,845 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "TESTE_NPS_ARP" |
| 2018-03-27 17:50:23,845 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_sql: searching for user 3 in Sql:192.168.1.14 |
| 2018-03-27 17:50:23,865 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: sql state - 07005, sql error - unixODBC]Bindings were not allocated properly. |
| 2018-03-27 17:50:23,865 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: SQL down 07005 unixODBC]Bindings were not allocated properly. |
| 2018-03-27 17:50:23,865 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_sql_unixodbc: rlm_sql will attempt to reconnect |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: sql state - HY010, sql error - unixODBC]Driver Manager]Function sequence error |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: SQL down HY010 unixODBC]Driver Manager]Function sequence error |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_sql_unixodbc: rlm_sql will attempt to reconnect |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql (authsrc_3005): failed after re-connect |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: sql state - HY010, sql error - unixODBC]Driver Manager]Function sequence error |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_sql_unixodbc: SQL down HY010 unixODBC]Driver Manager]Function sequence error |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_auth_check: Auth-Type not set. |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] ERROR RadiusServer.Radius - rlm_auth_check: Auth-Type not set or authentication methods have not been configured. Rejecting it. |
| 2018-03-27 17:50:23,882 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr f0d7aae6e917 |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3003 entity id = 29 |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3003 |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3003|entityId=29 |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3003|entity=Device |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 r=psauto-1522078721-91 h=135 r=R0000002a-01-5abaae8f] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2018-03-27 17:50:23,884 | [RequestHandler-1-0x7fc2deff7700 h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 h=914 c=R0000002a-01-5abaae8f] INFO Core.PETaskRoleMapping - Roles: |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2018-03-27 17:50:23,885 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2018-03-27 17:50:23,886 | [RequestHandler-1-0x7fc2deff7700 h=917 c=R0000002a-01-5abaae8f] INFO Core.PETaskEnforcement - EnfProfiles: Allow Access Profile] |
| 2018-03-27 17:50:23,886 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2018-03-27 17:50:23,886 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2018-03-27 17:50:23,886 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 h=922 c=R0000002a-01-5abaae8f] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 h=918 c=R0000002a-01-5abaae8f] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
| 2018-03-27 17:50:23,887 | [RequestHandler-1-0x7fc2deff7700 h=918 c=R0000002a-01-5abaae8f] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Allow Access Profile] |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 h=918 c=R0000002a-01-5abaae8f] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 h=923 c=R0000002a-01-5abaae8f] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=919 c=R0000002a-01-5abaae8f] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
| 2018-03-27 17:50:23,888 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=921 c=R0000002a-01-5abaae8f] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2018-03-27 17:50:23,889 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2018-03-27 17:50:23,891 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - Policy Evaluation time = 8 ms |
| 2018-03-27 17:50:23,891 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
| 2018-03-27 17:50:23,891 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2018-03-27 17:50:23,891 | [Th 18 Req 42 SessId R0000002a-01-5abaae8f] INFO RadiusServer.Radius - Request processing time = 50 ms |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 h=925 c=R0000002a-01-5abaae8f] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 h=925 c=R0000002a-01-5abaae8f] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 h=924 c=R0000002a-01-5abaae8f] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2018-03-27 17:50:23,891 | [RequestHandler-1-0x7fc2deff7700 r=R0000002a-01-5abaae8f h=912 c=R0000002a-01-5abaae8f] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |