Request log details for session: R001bae62-01-61dca013
Time	Message
2022-01-10 16:07:31,362	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 157:169:58-38-79-52-D5-92
2022-01-10 16:07:31,367	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - Service Categorization time = 5 ms
2022-01-10 16:07:31,367	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "Wired Mac Authentication (CX)"
2022-01-10 16:07:31,367	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_sql: searching for user 58387952d592 in Local:localhost
2022-01-10 16:07:31,367	[RequestHandler-1-0x7fdb807e6700 r=psauto-1634140754-5220683 h=127 r=R001bae62-01-61dca013] INFO Core.ServiceReqHandler - Service classification result = Wired Mac Authentication (CX)
2022-01-10 16:07:31,368	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_sql: found user 58387952d592 in Local:localhost
2022-01-10 16:07:31,368	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - SQL User lookup time = 1 ms
2022-01-10 16:07:31,368	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
2022-01-10 16:07:31,370	[RequestHandler-1-0x7fdb807e6700 r=psauto-1634140754-5220684 h=135 r=R001bae62-01-61dca013] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 58387952d592
2022-01-10 16:07:31,370	[RequestHandler-1-0x7fdb807e6700 r=psauto-1634140754-5220684 h=135 r=R001bae62-01-61dca013] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser)
2022-01-10 16:07:31,370	[RequestHandler-1-0x7fdb807e6700 r=psauto-1634140754-5220684 h=135 r=R001bae62-01-61dca013] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
2022-01-10 16:07:31,370	[RequestHandler-1-0x7fdb807e6700 r=psauto-1634140754-5220684 h=135 r=R001bae62-01-61dca013] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
2022-01-10 16:07:31,371	[RequestHandler-1-0x7fdb807e6700 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
2022-01-10 16:07:31,371	[RequestHandler-1-0x7fdb807e6700 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
2022-01-10 16:07:31,371	[RequestHandler-1-0x7fdb807e6700 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
2022-01-10 16:07:31,371	[RequestHandler-1-0x7fdb807e6700 h=40498079 c=R001bae62-01-61dca013] WARN REC.EvaluatorCtx - Prerequisites set is empty, not populating the Request Map
2022-01-10 16:07:31,371	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
2022-01-10 16:07:31,372	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498080 c=R001bae62-01-61dca013] INFO Core.PETaskRoleMapping - Roles: User Authenticated]
2022-01-10 16:07:31,372	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
2022-01-10 16:07:31,372	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
2022-01-10 16:07:31,373	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
2022-01-10 16:07:31,373	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
2022-01-10 16:07:31,376	[RequestHandler-1-0x7fdb807e6700 h=40498083 c=R001bae62-01-61dca013] INFO Core.PETaskEnforcement - EnfProfiles: Aruba - Wired Update Endpoint Location, Update Endpoint Known], Trusted-Printer DUR (CX)
2022-01-10 16:07:31,376	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
2022-01-10 16:07:31,376	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
2022-01-10 16:07:31,376	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
2022-01-10 16:07:31,378	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
2022-01-10 16:07:31,378	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
2022-01-10 16:07:31,378	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498090 c=R001bae62-01-61dca013] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498087 c=R001bae62-01-61dca013] WARN Common.AppEnfProfileTable - getAppType: Failed for id=3044
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498087 c=R001bae62-01-61dca013] WARN Common.AppEnfProfileTable - getAppType: Failed for id=51
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498085 c=R001bae62-01-61dca013] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498085 c=R001bae62-01-61dca013] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Trusted-Printer DUR (CX)
2022-01-10 16:07:31,379	[RequestHandler-1-0x7fdb807e6700 h=40498085 c=R001bae62-01-61dca013] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 h=40498091 c=R001bae62-01-61dca013] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
2022-01-10 16:07:31,380	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] WARN Core.PETaskPostAuthEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg=
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - Post auth enforcement profiles used: Aruba - Wired Update Endpoint Location, Update Endpoint Known]
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownAutzParams to fetch for PostAuthEnfProfiles: :
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - UnknownNAutzParams to fetch for PostAuthEnfProfiles: : Radius:IETF:NAS-Identifier, Radius:IETF:NAS-Port-Id
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - Discarding attr name=Endpoint:Location|attr value=SEUAS6-1:1/8/44 as the entity = 58387952d592 already possesses this value
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 58387952d592
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - Discarding attr name=Status-Update:Endpoint|attr value=Known as the entity = 58387952d592 already possesses this value
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthHTTPRequest: Sending PostAuthEnfRequest {"content":{"auth_source_id":4,"mac_address":"58387952d592","nas_ip":"10.130.100.61","post_auth_actions":{"enf_profile_name":"Aruba - Wired Update Endpoint Location","enf_profile_type":"EntityUpdate","params":null},{"enf_profile_name":"Update Endpoint Known]","enf_profile_type":"EntityUpdate","params":null}],"user_id":"58387952d592"},"id":"R001bae62-01-61dca013","name":"pactrl_enf_request"}
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498089 c=R001bae62-01-61dca013] INFO Core.PETaskPostAuthEnfProfileBuilder - sendPostAuthResponse: Done sending the PostAuthEnfRequest
2022-01-10 16:07:31,381	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498086 c=R001bae62-01-61dca013] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskMacAuthResetHandler **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
2022-01-10 16:07:31,382	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
2022-01-10 16:07:31,387	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - Policy Evaluation time = 19 ms
2022-01-10 16:07:31,387	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_policy: Received Accept Enforcement Profile
2022-01-10 16:07:31,387	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_policy: Added Class attribute with value Class = 0x2c4a8dff1f7e4a1d80cc8a39fb3faa5cd50b0000000000005230303162616536322d30312d36316463613031330000000000000000000000
2022-01-10 16:07:31,387	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response
2022-01-10 16:07:31,387	[RequestHandler-1-0x7fdb807e6700 h=40498094 c=R001bae62-01-61dca013] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
2022-01-10 16:07:31,387	[RequestHandler-1-0x7fdb807e6700 h=40498094 c=R001bae62-01-61dca013] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2022-01-10 16:07:31,387	[RequestHandler-1-0x7fdb807e6700 h=40498093 c=R001bae62-01-61dca013] WARN Core.RadiusEnfProfileHelper - getSessionTimeoutInSecs: SessionTimeout attribute missing in output
2022-01-10 16:07:31,387	[RequestHandler-1-0x7fdb807e6700 h=40498092 c=R001bae62-01-61dca013] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2022-01-10 16:07:31,387	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
2022-01-10 16:07:31,388	[Th 60684 Req 7430610 SessId R001bae62-01-61dca013] INFO RadiusServer.Radius - Request processing time = 25 ms
2022-01-10 16:07:31,388	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
2022-01-10 16:07:31,388	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
2022-01-10 16:07:31,388	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498096] ERROR Core.MacAuthSessionQueryEventHandler - Failed to get MacAuth session info for 58387952d592
2022-01-10 16:07:31,388	[RequestHandler-1-0x7fdb807e6700 h=40498093 c=R001bae62-01-61dca013] WARN Core.PETaskMacAuthResetHandler - handleMacAuthSessionResponseEv: Error reading MacAuth session info. Error=Failed to get MacAuth session info for 58387952d592
2022-01-10 16:07:31,389	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - ** Completed PETaskMacAuthResetHandler **
2022-01-10 16:07:31,389	[RequestHandler-1-0x7fdb807e6700 r=R001bae62-01-61dca013 h=40498078 c=R001bae62-01-61dca013] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***