| Time | Message |
|---|---|
| 2017-11-28 13:26:27,836 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 178:324:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,843 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-389 h=223 r=R000000a3-01-5a1cc953] INFO Core.ServiceReqHandler - Service classification result = {WIFI-Auth-BYOT} |
| 2017-11-28 13:26:27,844 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - Service Categorization time = 7 ms |
| 2017-11-28 13:26:27,844 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "{WIFI-Auth-BYOT}" |
| 2017-11-28 13:26:27,844 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_ldap: searching for user byot.test in AD:SVR-AD16-01.knox.vic.edu.au |
| 2017-11-28 13:26:27,846 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_ldap: found user byot.test in AD:SVR-AD16-01.knox.vic.edu.au |
| 2017-11-28 13:26:27,846 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - LDAP/AD User lookup time = 2 ms |
| 2017-11-28 13:26:27,846 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_eap_peap: Initiate |
| 2017-11-28 13:26:27,846 | [Th 44 Req 560 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 178:88:AC-CF-5C-47-30-93:AIwAGgC+AOgwAgAAbGG0UMOFv7b/iyz96ZshJA== |
| 2017-11-28 13:26:27,868 | [Th 41 Req 561 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 175:358:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,868 | [Th 41 Req 561 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_eap_tls: Initiate |
| 2017-11-28 13:26:27,868 | [Th 41 Req 561 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 175:88:AC-CF-5C-47-30-93:AAQAygADALMxAgAAW+kr+cZvB1BbvKGHpEWsTA== |
| 2017-11-28 13:26:27,887 | [Th 42 Req 562 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 154:513:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,893 | [Th 42 Req 562 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A |
| 2017-11-28 13:26:27,893 | [Th 42 Req 562 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A |
| 2017-11-28 13:26:27,894 | [Th 42 Req 562 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 154:1124:AC-CF-5C-47-30-93:AMUAHgCVACAyAgAAznxccLszjsoXiHqwbbvLMA== |
| 2017-11-28 13:26:27,901 | [Th 43 Req 563 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 83:358:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,902 | [Th 43 Req 563 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 83:1120:AC-CF-5C-47-30-93:AEwAtAB1ANYzAgAAIcUM0s4sYxaRuCRkDc5xrQ== |
| 2017-11-28 13:26:27,909 | [Th 44 Req 564 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 210:358:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,909 | [Th 44 Req 564 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 210:1120:AC-CF-5C-47-30-93:AJsAEQAgAGQ0AgAAmIjh4JGt5zZ6MIrK6D4yJQ== |
| 2017-11-28 13:26:27,916 | [Th 41 Req 565 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 72:358:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,917 | [Th 41 Req 565 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 72:550:AC-CF-5C-47-30-93:AKIAXwCqAFc1AgAA8cL8d4fCYkhIFnpa5AlJoQ== |
| 2017-11-28 13:26:27,931 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "{WIFI-Auth-BYOT}" - 247:369:AC-CF-5C-47-30-93 |
| 2017-11-28 13:26:27,932 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] ERROR RadiusServer.Radius - TLS Alert read:warning:close notify |
| 2017-11-28 13:26:27,932 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] ERROR RadiusServer.Radius - TLS_accept:failed in SSLv3 read client certificate A |
| 2017-11-28 13:26:27,932 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] ERROR RadiusServer.Radius - rlm_eap_tls: SSL_read failed in a system call (-1), TLS session fails. error:140940E5:SSL routines:ssl3_read_bytes:ssl handshake failure |
| 2017-11-28 13:26:27,932 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] ERROR RadiusServer.Radius - rlm_eap_tls: TLS Handshake failed |
| 2017-11-28 13:26:27,932 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. |
| 2017-11-28 13:26:27,936 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO Common.EndpointTable - Returning NULL (EndpointPtr) for macAddr accf5c473093 |
| 2017-11-28 13:26:27,936 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3001 entity id = 29 |
| 2017-11-28 13:26:27,936 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3001 |
| 2017-11-28 13:26:27,936 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3001|entityId=29 |
| 2017-11-28 13:26:27,936 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3001|entity=Device |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO TAT.EndpointTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Endpoint) |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 r=psauto-1511500478-390 h=239 r=R000000a3-01-5a1cc953] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** |
| 2017-11-28 13:26:27,937 | [RequestHandler-1-0x7ff0871f8700 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** |
| 2017-11-28 13:26:27,938 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** |
| 2017-11-28 13:26:27,939 | [RequestHandler-1-0x7ff0871f8700 h=3670 c=R000000a3-01-5a1cc953] INFO Core.PETaskRoleMapping - Roles: Guest] |
| 2017-11-28 13:26:27,939 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** |
| 2017-11-28 13:26:27,939 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** |
| 2017-11-28 13:26:27,940 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** |
| 2017-11-28 13:26:27,940 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** |
| 2017-11-28 13:26:27,941 | [RequestHandler-1-0x7ff0871f8700 h=3673 c=R000000a3-01-5a1cc953] INFO Core.PETaskEnforcement - EnfProfiles: Deny Access Profile] |
| 2017-11-28 13:26:27,941 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** |
| 2017-11-28 13:26:27,942 | [RequestHandler-1-0x7ff0871f8700 h=3679 c=R000000a3-01-5a1cc953] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device |
| 2017-11-28 13:26:27,943 | [RequestHandler-1-0x7ff0871f8700 h=3674 c=R000000a3-01-5a1cc953] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=DENY |
| 2017-11-28 13:26:27,943 | [RequestHandler-1-0x7ff0871f8700 h=3674 c=R000000a3-01-5a1cc953] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Deny Access Profile] |
| 2017-11-28 13:26:27,943 | [RequestHandler-1-0x7ff0871f8700 h=3674 c=R000000a3-01-5a1cc953] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 |
| 2017-11-28 13:26:27,943 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** |
| 2017-11-28 13:26:27,943 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder ** |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 h=3680 c=R000000a3-01-5a1cc953] INFO Core.PETaskCliEnforcement - startHandler: Request rejected. Skip CLI enforcement |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** |
| 2017-11-28 13:26:27,944 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3678 c=R000000a3-01-5a1cc953] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device |
| 2017-11-28 13:26:27,945 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** |
| 2017-11-28 13:26:27,946 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3675 c=R000000a3-01-5a1cc953] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device |
| 2017-11-28 13:26:27,946 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** |
| 2017-11-28 13:26:27,946 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** |
| 2017-11-28 13:26:27,946 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** |
| 2017-11-28 13:26:27,946 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** |
| 2017-11-28 13:26:27,950 | [RequestHandler-1-0x7ff0871f8700 h=3682 c=R000000a3-01-5a1cc953] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs |
| 2017-11-28 13:26:27,950 | [RequestHandler-1-0x7ff0871f8700 h=3682 c=R000000a3-01-5a1cc953] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2017-11-28 13:26:27,951 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - Policy Evaluation time = 19 ms |
| 2017-11-28 13:26:27,951 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_policy: Received Deny Enforcement Profile |
| 2017-11-28 13:26:27,951 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response |
| 2017-11-28 13:26:27,951 | [Th 42 Req 566 SessId R000000a3-01-5a1cc953] INFO RadiusServer.Radius - Request processing time = 115 ms |
| 2017-11-28 13:26:27,951 | [RequestHandler-1-0x7ff0871f8700 h=3681 c=R000000a3-01-5a1cc953] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr |
| 2017-11-28 13:26:27,951 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** |
| 2017-11-28 13:26:27,951 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** |
| 2017-11-28 13:26:27,951 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** |
| 2017-11-28 13:26:27,951 | [RequestHandler-1-0x7ff0871f8700 r=R000000a3-01-5a1cc953 h=3668 c=R000000a3-01-5a1cc953] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed *** |