Request log details for session: R000c80fb-01-5a5cb5a5

Time Message
2018-01-15 09:07:33,129 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634503 h=175 r=R000c80fb-01-5a5cb5a5] INFO Core.ServiceReqHandler - Service classification result = TEST WIRED 202Regina Zone AVAYA
2018-01-15 09:07:33,241 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.EndpointTable - Returning EndpointSPtr for macAddr 001765ff2f47
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.AuthLocalUserTable - Returning AuthLocalUserSPtr for user ID ipphone
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3066 entity id = 29
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for NAD instance=3066
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for NAD instanceId=3066|entityId=29
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=3066|entity=Device
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3006 entity id = 30
2018-01-15 09:07:33,242 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for AuthLocalUser instance=3006
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - attr name SwitchIP with value 10.10.10.200 inserted
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - attr name SwitchIPString with value 10.10.10.200 inserted
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - attr name SwitchPort with value 11 inserted
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Built tag mapping table from jsonb attributes
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Built 3 tag(s) for instanceId=3006|entityId=30|entityName=AuthLocalUsers
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - No InstanceTagDefCacheMap found for instance id = 3006 entity id = 30. Building the new InstanceTagDefCacheMap
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO TAT.GuTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL GuestUser)
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - No TagDefCacheMap could be found for instance id = 85946 entity id = 72
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Building the TagDefMapTable for Endpoint instance=85946
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO Common.TagDefinitionCacheTable - Built 0 tag(s) for instanceId=85946|entityId=72|entityName=Endpoint
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO TAT.TagAttrHolderBuilder - No tags built for instanceId=85946|entity=Endpoint
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 r=psauto-1515691695-2634504 h=187 r=R000c80fb-01-5a5cb5a5] INFO TAT.OnboardTagAttrHolderBuilder - buildAttrHolder: Tags cannot be built for instanceId=0 (NULL Onboard Device User)
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Started ***
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskAuthSourceRestriction **
2018-01-15 09:07:33,247 [RequestHandler-1-0x7f97e47e3700 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskRoleMapping **
2018-01-15 09:07:33,250 [RequestHandler-1-0x7f97e47e3700 h=18026360 c=R000c80fb-01-5a5cb5a5] WARN REC.EvaluatorCtx - Prerequisites set is empty, not populating the Request Map
2018-01-15 09:07:33,251 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskAuthSourceRestriction **
2018-01-15 09:07:33,373 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026361 c=R000c80fb-01-5a5cb5a5] INFO Common.AuthLocalUserTable - Returning AuthLocalUserSPtr for user ID ipphone
2018-01-15 09:07:33,373 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026361 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskRoleMapping - Roles: IPPhone, NAS-IP-Port-Match, User Authenticated]
2018-01-15 09:07:33,373 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskRoleMapping **
2018-01-15 09:07:33,373 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskPolicyResult **
2018-01-15 09:07:33,374 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskPolicyResult **
2018-01-15 09:07:33,374 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskEnforcement **
2018-01-15 09:07:33,407 [AuthReqThreadPool-9-0x7f98ad31b700 r=R000c80fb-01-5a5cb5a5 h=58] INFO ExtDB.DBHandle - Creating DB Connection with ODBC;DRIVER=PostgreSQL;SERVER=localhost;PORT=6432;DATABASE=tipsdb;UID=appuser;connect_timeout=15;stmt_query_timeout=10
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 h=18026398 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskEnforcement - EnfProfiles: WIRED 202Regina F V2600
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskEnforcement **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskRadiusEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskRadiusCoAEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskAppEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskAgentEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskPostAuthEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskGenericEnfProfileBuilder **
2018-01-15 09:07:33,450 [RequestHandler-1-0x7f97e47e3700 h=18026421 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskGenericEnfProfileBuilder - getApplicableProfiles: No App enforcement (Generic) profiles applicable for this device
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 h=18026416 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskRadiusEnfProfileBuilder - EnfProfileAction=ACCEPT
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 h=18026416 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskRadiusEnfProfileBuilder - Radius enfProfiles used: WIRED 202Regina F V2600
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 h=18026416 c=R000c80fb-01-5a5cb5a5] INFO Core.EnfProfileComputer - getFinalSessionTimeout: sessionTimeout = 10800
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskGenericEnfProfileBuilder **
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskAgentEnfProfileBuilder **
2018-01-15 09:07:33,451 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskAppEnfProfileBuilder **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskCliEnforcement **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 h=18026422 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskCliEnforcement - startHandler: No commands for CLI enforcement
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskRadiusEnfProfileBuilder **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskCliEnforcement **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026420 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskPostAuthEnfProfileBuilder - getApplicableProfiles: No Post auth enforcement profiles applicable for this device
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026417 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskRadiusCoAEnfProfileBuilder - getApplicableProfiles: No radius_coa enforcement profiles applicable for this device
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskPostAuthEnfProfileBuilder **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskRadiusCoAEnfProfileBuilder **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskAuthStatusInfo **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskOutputPolicyRes **
2018-01-15 09:07:33,452 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Starting PETaskSessionLog **
2018-01-15 09:07:33,455 [RequestHandler-1-0x7f97e47e3700 h=18026424 c=R000c80fb-01-5a5cb5a5] INFO Core.XpipPolicyResHandler - populateResponseTlv: PETaskPostureOutput does not exist. Skip sending posture VAFs
2018-01-15 09:07:33,455 [RequestHandler-1-0x7f97e47e3700 h=18026424 c=R000c80fb-01-5a5cb5a5] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2018-01-15 09:07:33,456 [RequestHandler-1-0x7f97e47e3700 h=18026423 c=R000c80fb-01-5a5cb5a5] INFO Core.PolicyResCollector - getSohr: Failed to generate Sohr
2018-01-15 09:07:33,456 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskSessionLog **
2018-01-15 09:07:33,456 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskOutputPolicyRes **
2018-01-15 09:07:33,456 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - ** Completed PETaskAuthStatusInfo **
2018-01-15 09:07:33,456 [RequestHandler-1-0x7f97e47e3700 r=R000c80fb-01-5a5cb5a5 h=18026359 c=R000c80fb-01-5a5cb5a5] INFO Core.PETaskScheduler - *** PE_TASK_SCHEDULE_RADIUS Completed ***