Request log details for session: R04dd72de-04-590a40de Time Message 2017-05-03 16:43:10,654 [Th 6200471 Req 730145675 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 108:195:B853AC7B72C5 2017-05-03 16:43:10,657 [RequestHandler-1-0x7f89097ab700 r=psauto-1481870856-178410344 h=607 r=R04dd72de-04-590a40de] INFO Core.ServiceReqHandler - Service classification result = NSU_802.1x Aruba Service Aruba 802.1X Wireless 2017-05-03 16:43:10,658 [Th 6200471 Req 730145675 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - Service Categorization time = 4 ms 2017-05-03 16:43:10,658 [Th 6200471 Req 730145675 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "NSU_802.1x Aruba Service Aruba 802.1X Wireless" 2017-05-03 16:43:10,658 [Th 6200471 Req 730145675 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_eap_peap: Initiate 2017-05-03 16:43:10,658 [Th 6200471 Req 730145675 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 108:88:B853AC7B72C5:AP8AxQAtAF2LI4UrxQJ9BZZzcbM2QIFh2QCOEA== 2017-05-03 16:43:10,682 [Th 6200477 Req 730145680 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "NSU_802.1x Aruba Service Aruba 802.1X Wireless" - 106:385:B853AC7B72C5 2017-05-03 16:43:10,682 [Th 6200477 Req 730145680 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A 2017-05-03 16:43:10,682 [Th 6200477 Req 730145680 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read finished A 2017-05-03 16:43:10,682 [Th 6200477 Req 730145680 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 106:240:B853AC7B72C5:AFcAbQCeANaQI4UrlPn4dRtEV/KyNZ3ilSax4g== 2017-05-03 16:43:10,726 [Th 6200470 Req 730145683 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "NSU_802.1x Aruba Service Aruba 802.1X Wireless" - 241:295:B853AC7B72C5 2017-05-03 16:43:10,726 [Th 6200470 Req 730145683 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_eap_peap: Session established. 2017-05-03 16:43:10,726 [Th 6200470 Req 730145683 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_eap_peap: Skipping Phase2 because of session resumption & fast reconnect. 2017-05-03 16:43:10,726 [Th 6200470 Req 730145683 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 241:125:B853AC7B72C5:AAUAqwAXANSTI4Urp522DWEfk+8T35/toHZGng== 2017-05-03 16:43:10,734 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "NSU_802.1x Aruba Service Aruba 802.1X Wireless" - 165:269:B853AC7B72C5 2017-05-03 16:43:10,734 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation. 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO Common.EndpointTable - Returning NULL (EndpointPtr) for macAddr b853ac7b72c5 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3020 entity id = 29 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3020 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3020|entityId=29 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3020|entity=Device 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser) 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser) 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO TAT.EndpointTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Endpoint) 2017-05-03 16:43:10,737 [RequestHandler-2-0x7f89095aa700 r=psauto-1481870856-178410347 h=656 r=R04dd72de-04-590a40de] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User) 2017-05-03 16:43:10,738 [RequestHandler-2-0x7f89095aa700 h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started *** 2017-05-03 16:43:10,738 [RequestHandler-2-0x7f89095aa700 h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction ** 2017-05-03 16:43:10,738 [RequestHandler-2-0x7f89095aa700 h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping ** 2017-05-03 16:43:10,738 [RequestHandler-2-0x7f89095aa700 h=1502166984 c=R04dd72de-04-590a40de] WARN REC.EvaluatorCtx - Prerequisites set is empty, not populating the Request Map 2017-05-03 16:43:10,739 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction ** 2017-05-03 16:43:10,739 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(&(sAMAccountName=%{Host:Name}$)(objectClass=computer)), error=No values for param=Host:Name 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Ldap.LdapQuery - execute: Failed to construct filter=(&(sAMAccountName=%{Host:Name}$)(objectClass=computer)) 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(&(sAMAccountName=%{Onboard:Owner})(objectClass=user)), error=No values for param=Onboard:Owner 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Ldap.LdapQuery - execute: Failed to construct filter=(&(sAMAccountName=%{Onboard:Owner})(objectClass=user)) 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(distinguishedName=%{Onboard memberOf}), error=No values for param=Onboard memberOf 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Ldap.LdapQuery - execute: Failed to construct filter=(distinguishedName=%{Onboard memberOf}) 2017-05-03 16:43:10,740 [AuthReqThreadPool-9-0x7f8c31c28700 r=R04dd72de-04-590a40de h=114] WARN Ldap.LdapQuery - Failed to get value for attributes=Department, HostName, OSServicePack, Onboard Groups, OperatingSystem, Phone, Title] 2017-05-03 16:43:10,741 [RequestHandler-2-0x7f89095aa700 h=1502166985 c=R04dd72de-04-590a40de] INFO Core.PETaskRoleMapping - Roles: User Authenticated] 2017-05-03 16:43:10,741 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping ** 2017-05-03 16:43:10,741 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult ** 2017-05-03 16:43:10,741 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult ** 2017-05-03 16:43:10,742 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement ** 2017-05-03 16:43:10,742 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(&(sAMAccountName=%{Host:Name}$)(objectClass=computer)), error=No values for param=Host:Name 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Ldap.LdapQuery - execute: Failed to construct filter=(&(sAMAccountName=%{Host:Name}$)(objectClass=computer)) 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(&(sAMAccountName=%{Onboard:Owner})(objectClass=user)), error=No values for param=Onboard:Owner 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Ldap.LdapQuery - execute: Failed to construct filter=(&(sAMAccountName=%{Onboard:Owner})(objectClass=user)) 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Util.ParameterizedString - getReplacedStrings: Failed to replace parameString =(distinguishedName=%{Onboard memberOf}), error=No values for param=Onboard memberOf 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Ldap.LdapQuery - execute: Failed to construct filter=(distinguishedName=%{Onboard memberOf}) 2017-05-03 16:43:10,743 [AuthReqThreadPool-18-0x7f8c30a1f700 r=R04dd72de-04-590a40de h=123] WARN Ldap.LdapQuery - Failed to get value for attributes=Department, HostName, OSServicePack, Onboard Groups, OperatingSystem, Phone, Title] 2017-05-03 16:43:10,749 [RequestHandler-2-0x7f89095aa700 h=1502166988 c=R04dd72de-04-590a40de] INFO Core.PETaskEnforcement - EnfProfiles: NSUStudents 2017-05-03 16:43:10,749 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement ** 2017-05-03 16:43:10,749 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder ** 2017-05-03 16:43:10,749 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder ** 2017-05-03 16:43:10,749 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder ** 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder ** 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder ** 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 h=1502166994 c=R04dd72de-04-590a40de] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 h=1502166990 c=R04dd72de-04-590a40de] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 h=1502166990 c=R04dd72de-04-590a40de] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: NSUStudents 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 h=1502166990 c=R04dd72de-04-590a40de] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0 2017-05-03 16:43:10,750 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder ** 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder ** 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement ** 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 h=1502166995 c=R04dd72de-04-590a40de] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder ** 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166993 c=R04dd72de-04-590a40de] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement ** 2017-05-03 16:43:10,751 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166991 c=R04dd72de-04-590a40de] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device 2017-05-03 16:43:10,752 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder ** 2017-05-03 16:43:10,752 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder ** 2017-05-03 16:43:10,752 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo ** 2017-05-03 16:43:10,752 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes ** 2017-05-03 16:43:10,752 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog ** 2017-05-03 16:43:10,757 [RequestHandler-2-0x7f89095aa700 h=1502166997 c=R04dd72de-04-590a40de] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs 2017-05-03 16:43:10,757 [RequestHandler-2-0x7f89095aa700 h=1502166997 c=R04dd72de-04-590a40de] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2017-05-03 16:43:10,758 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - Policy Evaluation time = 23 ms 2017-05-03 16:43:10,758 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile 2017-05-03 16:43:10,758 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_policy: Added Class attribute with value Class = 0xf6d0e09619984faba70edb0e1046796ec00b0000000000005230346464373264652d30342d35393061343064650000000000000000000000 2017-05-03 16:43:10,758 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response 2017-05-03 16:43:10,758 [Th 6200469 Req 730145684 SessId R04dd72de-04-590a40de] INFO RadiusServer.Radius - Request processing time = 104 ms 2017-05-03 16:43:10,758 [RequestHandler-2-0x7f89095aa700 h=1502166996 c=R04dd72de-04-590a40de] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr 2017-05-03 16:43:10,758 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog ** 2017-05-03 16:43:10,758 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes ** 2017-05-03 16:43:10,758 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo ** 2017-05-03 16:43:10,758 [RequestHandler-2-0x7f89095aa700 r=R04dd72de-04-590a40de h=1502166983 c=R04dd72de-04-590a40de] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***