2 Replies Latest reply: Oct 15, 2012 8:11 AM by 968382 RSS

    Poor performance using policy agent 2.2 with Sun Access Manager

    968382
      Even if com.sun.am.policy.agents.config.do_sso_only is set to true, the policy agent sent a request to PolicyService (svcid="Policy") and it's take more than 8 seconds to receive a respose. Any idea why ??

      Agent Log

      2012-10-15 08:11:42.441MaxDebug 24211:130800 PolicyService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <RequestSet vers="1.0" svcid="Policy" reqid="9">
      <Request><![CDATA[
      <PolicyService version="1.0">
      <PolicyRequest requestId="2" appSSOToken="AQIC5wM2LY4SfcynHuhUJZ2ol3lBzD0LJVKLpP7ULh6sgcg=@AAJTSQACMDE=#">
      <GetResourceResults userSSOToken="AQIC5wM2LY4Sfczm02fTJAo4H1i82OGPsRWMs5t6D7bRaVQ=@AAJTSQACMDE=#" serviceName="iPlanetAMWebAgentService" resourceName="http://devappa11.dev.emergis:80" resourceScope="response-attributes-only">
      <EnvParameters>
      <AttributeValuePair>
      <Attribute name="requestIp"/>
      <Value>142.168.64.128</Value>
      </AttributeValuePair>
      </EnvParameters>
      <GetResponseDecisions>
      <Attribute name="uid"/>
      </GetResponseDecisions>
      </GetResourceResults>
      </PolicyRequest>
      </PolicyService>]]>
      </Request>
      </RequestSet>

      2012-10-15 08:11:42.441MaxDebug 24211:130800 PolicyService: BaseService::sendRequest Request line: POST /amserver/policyservice HTTP/1.0

      2012-10-15 08:11:42.441 Debug 24211:130800 PolicyService: BaseService::sendRequest Cookie and Headers =Host: devappf9.dev.emergis

      2012-10-15 08:11:42.441 Debug 24211:130800 PolicyService: BaseService::sendRequest Content-Length =Content-Length: 778
      .
      2012-10-15 08:11:42.441 Debug 24211:130800 PolicyService: BaseService::sendRequest Header Suffix =Accept: text/xml
      Content-Type: text/xml; charset=UTF-8


      2012-10-15 08:11:42.441MaxDebug 24211:130800 PolicyService: BaseService::sendRequest(): Total chunks: 24.
      2012-10-15 08:11:42.441MaxDebug 24211:130800 PolicyService: BaseService::sendRequest(): Sent 24 chunks.



      2012-10-15 08:11:50.801 Debug 24211:130800 PolicyService: HTTP Status = 200 (OK)
      2012-10-15 08:11:50.801MaxDebug 24211:130800 PolicyService: Http::Response::readAndParse(): Reading headers.
      2012-10-15 08:11:50.801MaxDebug 24211:130800 PolicyService: Server: Sun-ONE-Web-Server/6.1
      2012-10-15 08:11:50.801MaxDebug 24211:130800 PolicyService: Date: Mon, 15 Oct 2012 12:11:50 GMT
      2012-10-15 08:11:50.801MaxDebug 24211:130800 PolicyService: Content-type: text/html
      2012-10-15 08:11:50.801MaxDebug 24211:130800 PolicyService: Connection: close
      2012-10-15 08:11:50.801 Debug 24211:130800 PolicyService: Http::Response::readAndParse(): No content length in response.
      2012-10-15 08:11:50.802MaxDebug 24211:130800 all: Connection::waitForReply(): returns with status success.
      2012-10-15 08:11:50.802MaxDebug 24211:130800 PolicyService: Http::Response::readAndParse(): Completed processing the response with status: success
      2012-10-15 08:11:50.802MaxDebug 24211:130800 PolicyService: <?xml version="1.0" encoding="UTF-8" standalone="yes"?>
      <ResponseSet vers="1.0" svcid="policy" reqid="9">
      <Response><![CDATA[<PolicyService version="1.0" revisionNumber="30">
      <PolicyResponse requestId="2">
      <ResourceResult name="http://devappa11.dev.emergis:80">
      <PolicyDecision>
      <ResponseDecisions>
      <AttributeValuePair>
      <Attribute name="uid"/>
      <Value>cppuser1</Value>
      </AttributeValuePair>
      </ResponseDecisions>
      </PolicyDecision>
      </ResourceResult>
      </PolicyResponse>
      </PolicyService>
      ]]></Response>
      </ResponseSet>
        • 1. Re: Poor performance using policy agent 2.2 with Sun Access Manager
          968382
          Sam Policy Log

          10/15/2012 08:11:42:157 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyRequestHandler.processRequest(): content is
          <PolicyService version="1.0">
          <PolicyRequest requestId="2" appSSOToken="AQIC5wM2LY4SfcynHuhUJZ2ol3lBzD0LJVKLpP7ULh6sgcg=@AAJTSQACMDE=#">
          <GetResourceResults userSSOToken="AQIC5wM2LY4Sfczm02fTJAo4H1i82OGPsRWMs5t6D7bRaVQ=@AAJTSQACMDE=#" serviceName="iPlanetAMWebAgentService" resourceName="http://devappa11.dev.emergis:80" resourceScope="response-attributes-only">
          <EnvParameters>
          <AttributeValuePair>
          <Attribute name="requestIp"/>
          <Value>142.168.64.128</Value>
          </AttributeValuePair>
          </EnvParameters>
          <GetResponseDecisions>
          <Attribute name="uid"/>
          </GetResponseDecisions>
          </GetResourceResults>
          </PolicyRequest>
          </PolicyService>
          10/15/2012 08:11:42:159 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyRequestHandler.processRequest(): policy service object:<PolicyService version="1.0">
          <PolicyRequest appSSOToken="AQIC5wM2LY4SfcynHuhUJZ2ol3lBzD0LJVKLpP7ULh6sgcg=@AAJTSQACMDE=#" requestId="2">
          <GetResourceResults userSSOToken="AQIC5wM2LY4Sfczm02fTJAo4H1i82OGPsRWMs5t6D7bRaVQ=@AAJTSQACMDE=#" serviceName="iPlanetAMWebAgentService" resourceName="http://devappa11.dev.emergis:80" resourceScope="response-attributes-only">
          <EnvParameters>
          <AttributeValuePair>
          <Attribute name="requestIp"/>
          <Value>142.168.64.128</Value>
          </AttributeValuePair>
          </EnvParameters>
          <GetResponseDecisions>
          <Attribute name="uid"/>
          </GetResponseDecisions>
          </GetResourceResults>
          </PolicyRequest>
          </PolicyService>

          10/15/2012 08:11:42:159 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyRequestHandler.processPolicyRequest(): req received:
          <PolicyRequest appSSOToken="AQIC5wM2LY4SfcynHuhUJZ2ol3lBzD0LJVKLpP7ULh6sgcg=@AAJTSQACMDE=#" requestId="2">
          <GetResourceResults userSSOToken="AQIC5wM2LY4Sfczm02fTJAo4H1i82OGPsRWMs5t6D7bRaVQ=@AAJTSQACMDE=#" serviceName="iPlanetAMWebAgentService" resourceName="http://devappa11.dev.emergis:80" resourceScope="response-attributes-only">
          <EnvParameters>
          <AttributeValuePair>
          <Attribute name="requestIp"/>
          <Value>142.168.64.128</Value>
          </AttributeValuePair>
          </EnvParameters>
          <GetResponseDecisions>
          <Attribute name="uid"/>
          </GetResponseDecisions>
          </GetResourceResults>
          </PolicyRequest>

          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyRequestHandler.processPolicyRequest(): respAttrs=
          [uid]
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          Evaluating policies at org o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          ResourceIndex.getPolicyNames - resourceName, policyNames=sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1:[SelfWriteAttributes, o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnly, o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmin, SelfReadAttributes, dc=dev^dc=emergis^^DatastoresReadOnly, dc=dev^dc=emergis^^RealmAdmin]
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          ResourceIndexManager.getPolicyNames - resourceName, policyNames=sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1:[SelfWriteAttributes, o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnly, o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmin, SelfReadAttributes, dc=dev^dc=emergis^^DatastoresReadOnly, dc=dev^dc=emergis^^RealmAdmin]
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyEvaluator.getPolicyDecision() principal, resource name, action names, policy names, orgName =uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [DELEGATE, MODIFY, READ], [SelfWriteAttributes, o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnly, o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmin, SelfReadAttributes, dc=dev^dc=emergis^^DatastoresReadOnly, dc=dev^dc=emergis^^RealmAdmin], o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=SelfWriteAttributescacheKey=/policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:160 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
          10/15/2012 08:11:42:161 AM EDT: Thread[service-j2ee-9,5,main]
          Policy SelfWriteAttributes is Using Policy evaluation order :1
          10/15/2012 08:11:42:161 AM EDT: Thread[service-j2ee-9,5,main]
          Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
          10/15/2012 08:11:42:161 AM EDT: Thread[service-j2ee-9,5,main]
          Subjects.isMember():getting subject evaluation results from resultCache of policy
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: called with Token: uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis EnvMap: {attributes=[uid], sun.am.requestedResource=[sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1], sun.am.requestedActions=[MODIFY, READ, DELEGATE]}
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: Is attributes [uid] subset of config attrs: [telephonenumber, sunIdentityServerDeviceStatus, userpassword, iplanet-am-user-password-reset-force-reset, givenname, mail, sn, cn, iplanet-am-user-password-reset-options, postaladdress, preferredlocale, description, sunIdentityServerDeviceKeyValue, iplanet-am-user-password-reset-question-answer]
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: attributes check:false
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          At Conditions.getConditionDecision():allowed,timeToLive, advices=false,9223372036854775807,{}
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], SelfWriteAttributes,
          10/15/2012 08:11:42:543 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnlycacheKey=/policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Policy o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnly is Using Policy evaluation order :1
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Subjects.isMember():getting subject evaluation results from resultCache of policy
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnly,
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmincacheKey=/policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Policy o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmin is Using Policy evaluation order :1
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          Subjects.isMember():getting subject evaluation results from resultCache of policy
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmin,
          10/15/2012 08:11:42:544 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=SelfReadAttributescacheKey=/policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          10/15/2012 08:11:42:545 AM EDT: Thread[service-j2ee-9,5,main]
          PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
          10/15/2012 08:11:42:545 AM EDT: Thread[service-j2ee-9,5,main]
          Policy SelfReadAttributes is Using Policy evaluation order :1
          10/15/2012 08:11:42:545 AM EDT: Thread[service-j2ee-9,5,main]
          Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
          10/15/2012 08:11:42:545 AM EDT: Thread[service-j2ee-9,5,main]
          Subjects.isMember():getting subject evaluation results from resultCache of policy
          10/15/2012 08:11:42:928 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: called with Token: uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis EnvMap: {attributes=[uid], sun.am.requestedResource=[sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1], sun.am.requestedActions=[MODIFY, READ, DELEGATE]}
          10/15/2012 08:11:42:928 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: attributes check:true
          10/15/2012 08:11:42:929 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: name: sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1 resource: [sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1]
          10/15/2012 08:11:42:929 AM EDT: Thread[service-j2ee-9,5,main]
          UserSelfCheckCondition.getConditionDecision: returning true
          10/15/2012 08:11:42:929 AM EDT: Thread[service-j2ee-9,5,main]
          At Conditions.getConditionDecision():allowed,timeToLive, advices=true,9223372036854775807,{}
          10/15/2012 08:11:42:929 AM EDT: Thread[service-j2ee-9,5,main]
          at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], SelfReadAttributes, READ=[allow]

          10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
          at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=dc=dev^dc=emergis^^DatastoresReadOnlycacheKey=/policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
          • 2. Re: Poor performance using policy agent 2.2 with Sun Access Manager
            968382
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Policy dc=dev^dc=emergis^^DatastoresReadOnly is Using Policy evaluation order :1
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Subjects.isMember():getting subject evaluation results from resultCache of policy
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], dc=dev^dc=emergis^^DatastoresReadOnly,
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=dc=dev^dc=emergis^^RealmAdmincacheKey=/policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Policy dc=dev^dc=emergis^^RealmAdmin is Using Policy evaluation order :1
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Using policy evaluation order:SUBJECTS_CONDITIONS_RULES
            10/15/2012 08:11:48:511 AM EDT: Thread[service-j2ee-9,5,main]
            Subjects.isMember():getting subject evaluation results from resultCache of policy
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            at Policy.getPolicyDecision() principal, resource name, action names, policyName, policyDecision = uid=cppuser1,ou=people,o=NFLD-EHR,dc=dev,dc=emergis, sms://o=nfld-ehr,dc=dev,dc=emergis/sunIdentityRepositoryService/1.0/application/user/cppuser1, [MODIFY, READ, DELEGATE], dc=dev^dc=emergis^^RealmAdmin,
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=SelfWriteAttributescacheKey=/policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=o=nfld-ehr^dc=dev^dc=emergis^^DatastoresReadOnlycacheKey=/policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=o=nfld-ehr^dc=dev^dc=emergis^^RealmAdmincacheKey=/policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:512 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=SelfReadAttributescacheKey=/policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=dc=dev^dc=emergis^^DatastoresReadOnlycacheKey=/policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyCache.getPolicy(orgName,policyName):orgName=o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis:policyName=dc=dev^dc=emergis^^RealmAdmincacheKey=/policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyCache:cacheKeys in cache:[policies/dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^policyadmin/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/selfreadattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/test jack/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^datastoresreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_system administrator_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/o=nfld-ehr^dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/jackpolicy/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis, /policies/selfwriteattributes/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/dc=dev^dc=emergis^^realmreadonly/default/1.0/iplanetampolicyservice/o=sunamhiddenrealmdelegationservicepermissions,ou=services,dc=dev,dc=emergis, /policies/p_dis_testjan1_null/default/1.0/iplanetampolicyservice/o=nfld-ehr,dc=dev,dc=emergis, /policies/routetonfld-ehr/default/1.0/iplanetampolicyservice/dc=dev,dc=emergis]
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyEvaluator.getPolicyDecision() orgsToVist=[]
            10/15/2012 08:11:48:513 AM EDT: Thread[service-j2ee-9,5,main]
            at PolicyEvaluator.getPolicyDecision() orgsToVist(after removing already visited orgs=[]
            10/15/2012 08:11:50:515 AM EDT: Thread[service-j2ee-9,5,main]
            PolicyRequestHandler.processRequest(): get response from policy framework:
            <PolicyService version="1.0" revisionNumber="30">
            <PolicyResponse requestId="2">
            <ResourceResult name="http://devappa11.dev.emergis:80">
            <PolicyDecision>
            <ResponseDecisions>
            <AttributeValuePair>
            <Attribute name="uid"/>
            <Value>cppuser1</Value>
            </AttributeValuePair>
            </ResponseDecisions>
            </PolicyDecision>
            </ResourceResult>
            </PolicyResponse>
            </PolicyService>