Issue:
Running Web Agent Option Pack, sometimes we see delays to process some operation. We discovered that the Policy Server delays the operation because it processes a lot of Server Commands. Here's a sample of a 7 second delay.
The thread 3231681424 finds 576 server commands to retrieve and
execute :
[04/16/2018][13:21:57.882][13:21:57][23455][3231681424][smldaputils.cpp:1959][SmLDAPOIDSearch][][][][][][][][][][][][][][][][][][][Handle='0xd3808e0'][][Start of call ldap_count_entries:How many entries?][][][][][][][][][][][][][][][]
[04/16/2018][13:21:57.882][13:21:57][23455][3231681424][smldaputils.cpp:1966][SmLDAPOIDSearch][][][][][][][][][][][][][][576][][][][][Handle='0xd3808e0'][][Return from call ldap_count_entries][][][][][][][][][][][][][][][]
then it retrieves all of them :
[04/16/2018][13:21:57.886][13:21:57][23455][3231681424][smldaputils.cpp:1211][SmSearchLDAP][][][][][][][][][][][][][][][][][][][Handle='0xd3808e0', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore', Scope=1, Filter='(&(smServerCommandOID4=13-0009c036-94f6-1ad4-a9b6-48440a42f018)(objectclass=smservercommand4))', attrsonly=0][][Start of call ldap_search_st:Search LDAP.][][][][][][][][][][][][][][][]
[04/16/2018][13:21:57.887][13:21:57][23455][3231681424][smldaputils.cpp:1217][SmSearchLDAP][][][][][][][][][][][][Success][][0][][][][][Handle='0xd3808e0', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore', Scope=1, Filter='(&(smServerCommandOID4=13-0009c036-94f6-1ad4-a9b6-48440a42f018)(objectclass=smservercommand4))', attrsonly=0][][Return from call ldap_search_st][][][][][][][][][][][][][][][]
[...]
[04/16/2018][13:21:59.412][13:21:59][23455][3231681424][smldaputils.cpp:1211][SmSearchLDAP][][][][][][][][][][][][][][][][][][][Handle='0xd3808e0', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore', Scope=1, Filter='(&(smServerCommandOID4=13-00069781-9565-1ad4-a97e-48ed0a42f028)(objectclass=smservercommand4))', attrsonly=0][][Start of call ldap_search_st:Search LDAP.][][][][][][][][][][][][][][][]
[04/16/2018][13:21:59.413][13:21:59][23455][3231681424][smldaputils.cpp:1217][SmSearchLDAP][][][][][][][][][][][][Success][][0][][][][][Handle='0xd3808e0', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore', Scope=1, Filter='(&(smServerCommandOID4=13-00069781-9565-1ad4-a97e-48ed0a42f028)(objectclass=smservercommand4))', attrsonly=0][][Return from call ldap_search_st][][][][][][][][][][][][][][][]
then it applies them :
[04/16/2018][13:21:59.490][13:21:59][23455][3231681424][SmDsUser.cpp:95][CSmDsUser::CSmDsUser][][][][][][][][][][][][][][][][][][][About to initialize User 'uid=jsmith,dc=training,dc=com' in dir 'myldapstore'][][Start of call InitUser.][][][][][][][][][][][][][][][]
[04/16/2018][13:21:59.491][13:21:59][23455][3231681424][SmDsUser.cpp:106][CSmDsUser::CSmDsUser][][][][][][][][][][][][][][][][][][][][][Return from call InitUser.][][][][][][][][][][][][][][][]
[04/16/2018][13:21:59.492][13:21:59][23455][3231681424][SmDsObj.cpp:94][CSmDsObj::IsValid][][][][][][][][][][][][][][][][][][][][][Start of call IsValid.][][][][][][][][][][][][][][][]
[04/16/2018][13:21:59.492][13:21:59][23455][3231681424][SmDsObj.cpp:96][CSmDsObj::IsValid][][][][][][][][][][][][][][true][][][][][][][Return from call IsValid.][][][][][][][][][][][][][][][]
until it finishes 13:22:03.782 :
[04/16/2018][13:22:03.781][13:22:03][23455][3231681424][SmDsDir.cpp:89][CSmDsDir::~CSmDsDir][][][][][][][][][][][][][][][][][][][Release DS Provider handle.][][Start of call Release.][][][][][][][][][][][][][][][]
[04/16/2018][13:22:03.782][13:22:03][23455][3231681424][SmDsDir.cpp:91][CSmDsDir::~CSmDsDir][][][][][][][][][][][][][][][][][][][][][Return from call Release.][][][][][][][][][][][][][][][]
So as there are operations going on about server and agent commands,
the thread 3713248144 is waiting until this operation ends to process
to set it and ends his task, which takes 7 seconds :
smtracedefault.log:
[04/16/2018][13:21:57.772][13:21:57][23455][3713248144][SmAuthUser.cpp:700][ServerTrace][][][][][][][][][][][][][][][][][][][][About to flush the cache for uid=jsmith,dc=training,dc=com][SmLimitAuthLogin: About to flush the cache for uid=jsmith,dc=training,dc=com][][][][][][][][][][][][][][][]
[04/16/2018][13:21:57.773][13:21:57][23455][3713248144][SmAuthAdminUser.cpp:166][CSmAuthAdminUser::Authenticate][][][][SiteMinder][][][][][][][][][][][][][][][][][Authentication succeeded.][][][][Sm_AuthApi_Accept][0][][][][][][][][][][]
[04/16/2018][13:22:03.784][13:22:03][23455][3713248144][smldaputils.cpp:1211][SmSearchLDAP][][][][][][][][][][][][][][][][][][][Handle='0xd3808e0', Root='ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore', Scope=1, Filter='(&(smAgentCommandOID4=14-000bf5c8-956b-1ad4-a9b6-48440a42f018)(objectclass=smagentcommand4))', attrsonly=0][][Start of call ldap_search_st:Search LDAP.][][][][][][][][][][][][][][][]
[04/16/2018][13:22:03.785][13:22:03][23455][3713248144][smldaputils.cpp:1849][SmAddLDAP][][][][][][][][][][][][][][][][][][][Handle='0xd3808e0', DN='smAgentCommandOID4=14-000bf5c8-956b-1ad4-a9b6-48440a42f018, ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore'][][Start of call ldap_add_s:Add LDAP.][][][][][][][][][][][][][][][]
[04/16/2018][13:22:03.792][13:22:03][23455][3713248144][smldaputils.cpp:1852][SmAddLDAP][][][][][][][][][][][][Success][][0][][][][][Handle='0xd3808e0', DN='smAgentCommandOID4=14-000bf5c8-956b-1ad4-a9b6-48440a42f018, ou=PolicySvr4,ou=SiteMinder,ou=Netegrity,o=mypstore'][][Return from call ldap_add_s][][][][][][][][][][][][][][][]
How can we solve this issue ?
Environment:
Web Agent Option Pack 12.52SP1CR02 on RedHat Jboss 6.4.0 RedHat 6 64bit;
Policy Server 12.52SP1CR02 on RedHat 5 64bit (special build);
Policy Server JVM on JDK 1.7.0_141;
LCL (SmAuthLimit) 2.2.2;
Policy Store on LDAP Oracle Directory 11.1.1.7.0
(Policy Store runs on the same machine than the
Policy Server);
User Store on LDAP Oracle Directory 11.1.1.7.0;
Session Store on Oracle 11.2.0.4;
Cause:
The Global Delivery Module "SmLimitAuthLogin" used to flush the Web
Agent caches and as such it is known to request Policy Server to
produce a lot of Server Command :
SmLimitAuthLogin About to flush the cache for
For every authentication in a SmLimitAuth protected
realm, SmLimitAuth calls the Policy Management API to
perform a cache flush on the account being logged into
in order to ensure that transactions by other users of
the same account will have to be processed by the
policy server and thus by the SmLimitAuth Check
function. The cache flush operation involves a write
to the policy store which, depending on your level
of authentication activity, may have a significant
impact on the performance of your authentications.
You may run your policy store machines on more
powerful machines or take other measures to improve
the performance of your policy store servers if
stress testing indicates that the cache flushes
are causing a significant performance delay in
authentications. One option is that if you are
not using agent caching, you can turn off the cache
flushing in SmLimitAuth with the NoCacheFlush
parameter (see below). If web agent caching is
used along with the NoCacheFlush parameter, user’s
with LCL invalided sessions will be able to continue
accessing URLs at the site they had previously
visited (and thus are authorized from the web agent
cache) but as soon as they access a new URL they will
be denied access and logged off (if the SiteMinder
logoff feature has been implemented and LCL configured
to redirect to the logoff URI for invalid sessions).
(Limit Concurrent Login for CA SiteMinder User Guide
Version 2.1.9)
Resolution:
The solution to those performance problems might be to disable the
Flush User Cache from the SmLimitAuthLogin module as stated by the
documentation.
Note that as per the same documentation, when setting NoCacheFlush in
LCL, you have to disable the caches responsible for authentication and
authorization on the Web Agents.
[...]
One option is that if you are
not using agent caching, you can turn off the cache
flushing in SmLimitAuth with the NoCacheFlush
parameter (see below).
(Limit Concurrent Login for CA SiteMinder User Guide
Version 2.1.9)
But doing this, you will increase the amount of Authentication and
Authorization requests that your Policy Server will need to handle.
In order to get a precise view on the impact on your environment, you
do need to benchmark it. We would advise you to get in touch with CA
Services for environment tuning purpose.
KB : KB000092949