Request log details for session: R0000e6ce-01-5dc53be5
Time	Message
2019-11-08 10:56:53,845	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: Starting Service Categorization - 188:205:D8F2CAA08967
2019-11-08 10:56:53,851	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120953 h=223 r=R0000e6ce-01-5dc53be5] INFO Core.ServiceReqHandler - Service classification result = 802.1X Wireless test 802.1X Wireless
2019-11-08 10:56:53,852	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - Service Categorization time = 7 ms
2019-11-08 10:56:53,852	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request has been categorized into service "802.1X Wireless test 802.1X Wireless"
2019-11-08 10:56:53,852	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:53,855	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_eap_peap: Initiate
2019-11-08 10:56:53,855	[Th 41 Req 104466 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 188:88:D8F2CAA08967:AMoAvQBGAI0SmAEACnc2tM8+GioFt91uA6GxRQ==
2019-11-08 10:56:53,862	[Th 44 Req 104467 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "802.1X Wireless test 802.1X Wireless" - 170:232:D8F2CAA08967
2019-11-08 10:56:53,862	[Th 44 Req 104467 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:53,864	[Th 44 Req 104467 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_eap_tls: Initiate
2019-11-08 10:56:53,864	[Th 44 Req 104467 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 170:88:D8F2CAA08967:ACwAUQAOACUTmAEAaV7413mwmttIAL3UDpcnVg==
2019-11-08 10:56:53,982	[Th 43 Req 104468 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "802.1X Wireless test 802.1X Wireless" - 178:392:D8F2CAA08967
2019-11-08 10:56:53,982	[Th 43 Req 104468 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:53,987	[Th 43 Req 104468 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A
2019-11-08 10:56:53,987	[Th 43 Req 104468 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - TLS_accept:error in SSLv3 read client certificate A
2019-11-08 10:56:53,987	[Th 43 Req 104468 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 178:1124:D8F2CAA08967:AOgA6wD8AA8UmAEA+zYEWb5OJGghBLdHcsfdmg==
2019-11-08 10:56:53,995	[Th 45 Req 104469 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "802.1X Wireless test 802.1X Wireless" - 176:232:D8F2CAA08967
2019-11-08 10:56:53,995	[Th 45 Req 104469 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:53,996	[Th 45 Req 104469 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 176:1120:D8F2CAA08967:AB4AjAAhAE4VmAEAnejqybhtNuESsOJZ5gaRvg==
2019-11-08 10:56:54,005	[Th 42 Req 104470 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "802.1X Wireless test 802.1X Wireless" - 179:232:D8F2CAA08967
2019-11-08 10:56:54,005	[Th 42 Req 104470 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:54,008	[Th 42 Req 104470 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 179:979:D8F2CAA08967:AE8APQAQAPwWmAEAoDBWugyf8NN98iABzjFYCw==
2019-11-08 10:56:54,019	[Th 41 Req 104471 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_service: The request was categorized into service "802.1X Wireless test 802.1X Wireless" - 180:232:D8F2CAA08967
2019-11-08 10:56:54,019	[Th 41 Req 104471 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_sql: searching for user K28581@u-ssi.net in Local:localhost
2019-11-08 10:56:54,020	[Th 41 Req 104471 SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - reqst_update_state: Access-Challenge 180:92:D8F2CAA08967:AHQAfwC+ALoXmAEArlGG/qE1KrnOlXIeA65BEg==
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Deleting request sessid - R0000e6ce-01-5dc53be5, state - AHQAfwC+ALoXmAEArlGG/qE1KrnOlXIeA65BEg=
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 188:205:88:D8F2CAA08967 recv 1573207013.845213 - resp 1573207013.855351
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 170:232:88:D8F2CAA08967 recv 1573207013.862312 - resp 1573207013.864755
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 178:392:1124:D8F2CAA08967 recv 1573207013.982370 - resp 1573207013.987593
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 176:232:1120:D8F2CAA08967 recv 1573207013.994984 - resp 1573207013.996675
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 179:232:979:D8F2CAA08967 recv 1573207014.5536 - resp 1573207014.8113
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] ERROR RadiusServer.Radius - reqst_clean_list: Packet 180:232:92:D8F2CAA08967 recv 1573207014.18880 - resp 1573207014.20792
2019-11-08 10:57:50,235	[main SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_policy: Starting Policy Evaluation.
2019-11-08 10:57:50,239	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] ERROR Common.NadClientTable - getNadClient: Unknown NadClient 100.93.4.252
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] ERROR Common.NadClientTable - getNadClient: Unknown NadClient 100.93.4.252
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO Common.EndpointTable - Returning NULL (EndpointPtr) for macAddr d8f2caa08967
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO Common.TagDefinitionCacheTable - No TagDefCacheMap could be found for instance id = 0 entity id = 29
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] WARN Common.TagDefinitionCacheTable - Failed to build TagDefinitionMap. Unknown NadClient for Id=0
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=0|entity=Device
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO TAT.AluTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL AuthLocalUser)
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO TAT.EndpointTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Endpoint)
2019-11-08 10:57:50,240	[RequestHandler-1-0x7fee7d7eb700 r=psauto-1566804968-120956 h=239 r=R0000e6ce-01-5dc53be5] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
2019-11-08 10:57:50,241	[RequestHandler-1-0x7fee7d7eb700 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
2019-11-08 10:57:50,241	[RequestHandler-1-0x7fee7d7eb700 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
2019-11-08 10:57:50,241	[RequestHandler-1-0x7fee7d7eb700 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
2019-11-08 10:57:50,242	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
2019-11-08 10:57:50,242	[RequestHandler-1-0x7fee7d7eb700 h=1076501 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskRoleMapping - Roles:
2019-11-08 10:57:50,242	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
2019-11-08 10:57:50,243	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
2019-11-08 10:57:50,243	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
2019-11-08 10:57:50,243	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 h=1076504 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskEnforcement - EnfProfiles: Deny Access Profile]
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 h=1076510 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 h=1076505 c=R0000e6ce-01-5dc53be5] ERROR Common.NadClientTable - getNadClient: Unknown NadClient 100.93.4.252
2019-11-08 10:57:50,244	[RequestHandler-1-0x7fee7d7eb700 h=1076505 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=DENY
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 h=1076505 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: Deny Access Profile]
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 h=1076505 c=R0000e6ce-01-5dc53be5] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 0
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 h=1076511 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskCliEnforcement - startHandler: Request rejected. Skip CLI enforcement
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
2019-11-08 10:57:50,245	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076506 c=R0000e6ce-01-5dc53be5] WARN Core.PETaskRadiusCoAEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg=
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076509 c=R0000e6ce-01-5dc53be5] WARN Core.PETaskPostAuthEnfProfileBuilder - handleHttpResponseEv: Fetching Radius attributes from battery failed, errMsg=
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076509 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
2019-11-08 10:57:50,246	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
2019-11-08 10:57:50,249	[RequestHandler-1-0x7fee7d7eb700 h=1076513 c=R0000e6ce-01-5dc53be5] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
2019-11-08 10:57:50,281	[RequestHandler-1-0x7fee7d7eb700 h=1076513 c=R0000e6ce-01-5dc53be5] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2019-11-08 10:57:50,281	[RequestHandler-1-0x7fee7d7eb700 h=1076512 c=R0000e6ce-01-5dc53be5] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2019-11-08 10:57:50,282	[main SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - Policy Evaluation time = 46 ms
2019-11-08 10:57:50,282	[main SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_policy: Received Deny Enforcement Profile
2019-11-08 10:57:50,282	[main SessId R0000e6ce-01-5dc53be5] INFO RadiusServer.Radius - rlm_policy: Policy Server reply does not contain Posture-Validation-Response
2019-11-08 10:57:50,282	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
2019-11-08 10:57:50,282	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
2019-11-08 10:57:50,282	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
2019-11-08 10:57:50,282	[RequestHandler-1-0x7fee7d7eb700 r=R0000e6ce-01-5dc53be5 h=1076499 c=R0000e6ce-01-5dc53be5] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***