| Time | Message |
|---|---|
| 2017-11-28 13:10:56,837 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 70:324:00-21-00-D2-73-3F |
| 2017-11-28 13:10:56,844 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-379 h=223 r=R000000a0-01-5a1cc5b0] INFO Core.ServiceReqHandler - Service classification result = {WIFI-Auth-BYOT} |
| 2017-11-28 13:10:56,845 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - Service Categorization time = 8 ms |
| 2017-11-28 13:10:56,845 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "{WIFI-Auth-BYOT}" |
| 2017-11-28 13:10:56,845 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_ldap: searching for user byot.test in AD:SVR-AD16-01.knox.vic.edu.au |
| 2017-11-28 13:10:56,845 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] ERROR RadiusServer.Radius - rlm_ldap: ldap_search() failed: LDAP connection lost. |
| 2017-11-28 13:10:56,845 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_ldap: Attempting reconnect |
| 2017-11-28 13:10:56,854 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_ldap: found user byot.test in AD:SVR-AD16-01.knox.vic.edu.au |
| 2017-11-28 13:10:56,855 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - LDAP/AD User lookup time = 9 ms |
| 2017-11-28 13:10:56,855 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_eap_peap: Initiate |
| 2017-11-28 13:10:56,855 | [Th 44 Req 540 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 70:88:00-21-00-D2-73-3F:AHAAwQBPAFwcAgAAYBZ0CiVkFIt88ytZLRgV5g== |
| 2017-11-28 13:10:56,861 | [Th 41 Req 541 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 33:358:00-21-00-D2-73-3F |
| 2017-11-28 13:10:56,861 | [Th 41 Req 541 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_eap_tls: Initiate |
| 2017-11-28 13:10:56,861 | [Th 41 Req 541 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 33:88:00-21-00-D2-73-3F:ABsA0wDGANwdAgAAaebcC8LjGxcG+RSmPSiG2A== |
| 2017-11-28 13:10:56,875 | [Th 42 Req 542 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 208:550:00-21-00-D2-73-3F |
| 2017-11-28 13:10:56,876 | [Th 42 Req 542 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A |
| 2017-11-28 13:10:56,876 | [Th 42 Req 542 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A |
| 2017-11-28 13:10:56,876 | [Th 42 Req 542 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 208:232:00-21-00-D2-73-3F:AA0AswAEACEeAgAABfkQKwtki5L/UwV7WbOrvA== |
| 2017-11-28 13:10:56,886 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 80:413:00-21-00-D2-73-3F |
| 2017-11-28 13:10:56,886 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_eap_tls: Session established. |
| 2017-11-28 13:10:56,887 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 002100d2733f |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3001 entity id = 29 |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3001 |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3001|entityId=29 |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3001|entity=Device |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2017-11-28 13:10:56,893 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-380 h=239 r=R000000a0-01-5a1cc5b0] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2017-11-28 13:10:56,894 | [RequestHandler-1-0x7ff0871f8700 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2017-11-28 13:10:56,894 | [RequestHandler-1-0x7ff0871f8700 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2017-11-28 13:10:56,894 | [RequestHandler-1-0x7ff0871f8700 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2017-11-28 13:10:56,895 | [RequestHandler-1-0x7ff0871f8700 h=3579 c=R000000a0-01-5a1cc5b0] WARN REC.EvaluatorCtx - Prerequisites set is empty, not populating the Request Map |
| 2017-11-28 13:10:56,895 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2017-11-28 13:10:56,898 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3580 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskRoleMapping - Roles: User Authenticated], {BYOT-Students} |
| 2017-11-28 13:10:56,898 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2017-11-28 13:10:56,898 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2017-11-28 13:10:56,899 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2017-11-28 13:10:56,899 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 h=3583 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskEnforcement - EnfProfiles: {VLAN-BYOT-Student} |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2017-11-28 13:10:56,900 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder ** |
| 2017-11-28 13:10:56,901 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2017-11-28 13:10:56,901 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2017-11-28 13:10:56,901 | [RequestHandler-1-0x7ff0871f8700 h=3589 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2017-11-28 13:10:56,901 | [RequestHandler-1-0x7ff0871f8700 h=3584 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT |
| 2017-11-28 13:10:56,901 | [RequestHandler-1-0x7ff0871f8700 h=3584 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: {VLAN-BYOT-Student} |
| 2017-11-28 13:10:56,902 | [RequestHandler-1-0x7ff0871f8700 h=3584 c=R000000a0-01-5a1cc5b0] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 |
| 2017-11-28 13:10:56,903 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder ** |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 h=3590 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2017-11-28 13:10:56,904 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3588 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3585 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2017-11-28 13:10:56,905 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2017-11-28 13:10:56,906 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2017-11-28 13:10:56,913 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - Policy Evaluation time = 25 ms |
| 2017-11-28 13:10:56,913 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 h=3592 c=R000000a0-01-5a1cc5b0] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 h=3592 c=R000000a0-01-5a1cc5b0] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 h=3591 c=R000000a0-01-5a1cc5b0] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2017-11-28 13:10:56,913 | [RequestHandler-1-0x7ff0871f8700 r=R000000a0-01-5a1cc5b0 h=3578 c=R000000a0-01-5a1cc5b0] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |
| 2017-11-28 13:10:56,914 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_policy: Added Class attribute with value Class = 0xa7ff9d52935640299f2e6c1e48834ca8c50b0000000000005230303030303061302d30312d35613163633562300000000000000000000000 |
| 2017-11-28 13:10:56,914 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2017-11-28 13:10:56,914 | [Th 43 Req 543 SessId R000000a0-01-5a1cc5b0] INFO RadiusServer.Radius - Request processing time = 77 ms |