Re: [389-users] ACIs caching issue

Mon, 16 Nov 2015 13:08:07 -0800

What is the "size limit" you are referring to? Search size limit? ... This particular search only returns a few attributes of a single entry. We've used the client to list larger number of entries and it works fine. 

Or is there a different configurable size limit? What should I look for?

Thanks,
Adrian

On 11/16/2015 12:23 PM, Mark Reynolds wrote:



On 11/16/2015 01:58 PM, Adrian Damian wrote:

Hi Mark,
Thanks for the quick reply. I don't exactly know how to read the logs but I've highlighted the parts that seem relevant.
The macro ACI is to allow read access to the members of a group on their own group: 

aci: (target="ldap:///($dn),ou=Groups,ou=abc")(targetattr = "*
")(version 3.0; acl "Members group read"; allow(read,search,compare) groupdn= 
"ldap:///($dn),ou=Groups,ou=abc";)



Java evaluation of the ACI when it fails:

"
...
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(15) " "Members group read"" [16/Nov/2015:10:17:46 -0800] NSACLPlugin - aclutil_evaluate_macro for aci ' "Members group read"' index '15' [16/Nov/2015:10:17:46 -0800] NSACLPlugin - ACL info: found matched_val ( "Members group read") for aci index 15in macro ht [16/Nov/2015:10:17:46 -0800] NSACLPlugin - Evaluating user uid=stmairs,ou=users,ou=abc in group cn=jcmt-mjlsg14b,ou=Groups,ou=abc? [16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in uid=admin,ou=Administrators,ou=TopologyManagement,o=NetscapeRoot [16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in cn=Configuration Administrators,ou=Groups,ou=TopologyManagement,o=NetscapeRoot [16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in uid=user,ou=Users,ou=abc 
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in cn=CadcDev,ou=abc
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in cn=jcmt-mjlsg14b,ou=Groups,ou=abc [16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in uid=user1,ou=users,ou=abc [16/Nov/2015:10:17:46 -0800] NSACLPlugin - -- Not in uid=user2,ou=users,ou=abc *[16/Nov/2015:10:17:46 -0800] NSACLPlugin - GroupEval:Looked at too many entries:(2, 10)** 
**[16/Nov/2015:10:17:46 -0800] NSACLPlugin - Evaluated ACL_DONT_KNOW
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - DS_LASGroupDnEval: Param group name:($dn),ou=Groups,ou=abc [16/Nov/2015:10:17:46 -0800] NSACLPlugin - Returning UNDEFINED for groupdn evaluation.* 
*Okay this looks like:

https://fedorahosted.org/389/ticket/47704
Which is fixed in 1.3.1 and up, but not 1.2.11. You can reopen the ticket asking if it can be backported to 1.2.11 (if possible - no promises).
Perhaps the java client is setting a "size limit", while python and ldapsearch are not?
Possible workaround would be change/remove the client size limit(if its set), and you can also try setting the size limit much higher in the DS configuration as well(like 30000 - this depends on the number of entries in the database, etc). I'm not sure these "workarounds" will work, but for now it's worth trying. 

Mark
*


...
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - ***BEGIN ACL INFO[ Name: "Members group read"]*** 
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - ACL Index:15   ACL_ELEVEL:6
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - ACI type:(compare search read target_attr acltxt allow_rule ) [16/Nov/2015:10:17:46 -0800] NSACLPlugin - ACI RULE type:(groupdn paramdn ) [16/Nov/2015:10:17:46 -0800] NSACLPlugin - Slapi_Entry DN:ou=groups,ou=abc [16/Nov/2015:10:17:46 -0800] NSACLPlugin - ***END ACL INFO***************************** 
...
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - Processed attr:uniqueMember for entry:cn=jcmt-mjlsg14b,ou=groups,ou=abc [16/Nov/2015:10:17:46 -0800] NSACLPlugin - 1. Evaluating ALLOW aci(14) " "Owner access and modify existing group"" 
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - Found READ SKIP in cache
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(15) " "Members group read"" 
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - Found READ SKIP in cache
[16/Nov/2015:10:17:46 -0800] NSACLPlugin - conn=57208 op=4 (main): Deny read on entry(cn=jcmt-mjlsg14b,ou=groups,ou=abc).attr(uniqueMember) to proxy (uid=auser,ou=users,ou=abc): no aci matched the subject by aci(3): aciname= "Configuration Administrators Group", acidn="dc=abc" 

"




Python or ldapseach execution of the same ACI:


"
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(15) " "Members group read"" [16/Nov/2015:10:29:32 -0800] NSACLPlugin - aclutil_evaluate_macro for aci ' "Members group read"' index '15' [16/Nov/2015:10:29:32 -0800] NSACLPlugin - ACL info: found matched_val ( "Members group read") for aci index 15in macro ht [16/Nov/2015:10:29:32 -0800] NSACLPlugin - Evaluating user uid=stmairs,ou=users,ou=abc in group cn=jcmt-mjlsg14b,ou=Groups,ou=abc? [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=admin,ou=Administrators,ou=TopologyManagement,o=NetscapeRoot [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in cn=Configuration Administrators,ou=Groups,ou=TopologyManagement,o=NetscapeRoot [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user1,ou=Users,ou=abc 
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in cn=CadcDev,ou=abc
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in cn=jcmt-mjlsg14b,ou=Groups,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user2,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user3,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user4,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user5,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user6,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user7,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user8,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user9,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- Not in uid=user10,ou=users,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - -- In cn=jcmt-gbs,ou=groups,ou=abc 
*[16/Nov/2015:10:29:32 -0800] NSACLPlugin - Evaluated ACL_TRUE**
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - Adding Group (cn=jcmt-gbs,ou=groups,ou=abc) ParentGroup (cn=jcmt-mjlsg14b,ou=Groups,ou=abc) to the IN GROUP List [16/Nov/2015:10:29:32 -0800] NSACLPlugin - Adding Group (cn=jcmt-mjlsg14b,ou=Groups,ou=abc) ParentGroup (NULL) to the IN GROUP List [16/Nov/2015:10:29:32 -0800] NSACLPlugin - DS_LASGroupDnEval: Param group name:($dn),ou=Groups,ou=abc*
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - ***BEGIN ACL INFO[ Name: "Members group read"]*** 
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - ACL Index:15   ACL_ELEVEL:6
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - ACI type:(compare search read target_attr acltxt allow_rule ) [16/Nov/2015:10:29:32 -0800] NSACLPlugin - ACI RULE type:(groupdn paramdn ) [16/Nov/2015:10:29:32 -0800] NSACLPlugin - Slapi_Entry DN:ou=groups,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - ***END ACL INFO*****************************
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - Num of ALLOW Handles:6, DENY handles:0 [16/Nov/2015:10:29:32 -0800] NSACLPlugin - Processed attr:uniqueMember for entry:cn=jcmt-mjlsg14b,ou=groups,ou=abc [16/Nov/2015:10:29:32 -0800] NSACLPlugin - 1. Evaluating ALLOW aci(14) " "Owner access and modify existing group"" 
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - Found READ SKIP in cache
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(15) " "Members group read"" 
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - Found READ ALLOW in cache
[16/Nov/2015:10:29:32 -0800] NSACLPlugin - conn=57315 op=1 (main): Allow read on entry(cn=jcmt-mjlsg14b,ou=groups,ou=abc).attr(uniqueMember) to proxy (uid=auser,ou=users,ou=abc): cached allow by aci(15) 
"



Java right after running the Python client (when it succeeds):


"
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(20) " "Members group read"" [16/Nov/2015:10:41:43 -0800] NSACLPlugin - aclutil_evaluate_macro for aci ' "Members group read"' index '20' [16/Nov/2015:10:41:43 -0800] NSACLPlugin - ACL info: found matched_val ( "Members group read") for aci index 20in macro ht [16/Nov/2015:10:41:43 -0800] NSACLPlugin - Evaluating user uid=stmairs,ou=users,ou=abc in group cn=jcmt-mjlsg14b,ou=Groups,ou=abc? [16/Nov/2015:10:41:43 -0800] NSACLPlugin - -- In cn=jcmt-gbs,ou=groups,ou=abc [16/Nov/2015:10:41:43 -0800] NSACLPlugin - -- In cn=jcmt-mjlsg14b,ou=Groups,ou=abc 
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - Evaluated ACL_TRUE

...
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - 2. Evaluating ALLOW aci(20) " "Members group read"" [16/Nov/2015:10:41:43 -0800] NSACLPlugin - aclutil_evaluate_macro for aci ' "Members group read"' index '20' [16/Nov/2015:10:41:43 -0800] NSACLPlugin - ACL info: found matched_val ( "Members group read") for aci index 20in macro ht [16/Nov/2015:10:41:43 -0800] NSACLPlugin - Evaluating user uid=stmairs,ou=users,ou=abc in group cn=jcmt-mjlsg14b,ou=Groups,ou=abc? [16/Nov/2015:10:41:43 -0800] NSACLPlugin - -- In cn=jcmt-gbs,ou=groups,ou=abc [16/Nov/2015:10:41:43 -0800] NSACLPlugin - -- In cn=jcmt-mjlsg14b,ou=Groups,ou=abc 
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - Evaluated ACL_TRUE
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - DS_LASGroupDnEval: Param group name:($dn),ou=Groups,ou=abc [16/Nov/2015:10:41:43 -0800] NSACLPlugin - conn=57465 op=52 (main): Allow read on entry(cn=jcmt-mjlsg14b,ou=admingroups,ou=abc).attr(nsUniqueId) to proxy (uid=stmairs,ou=users,ou=abc): allowed by aci(20): aciname= "Members group read", acidn="ou=admingroups,ou=abc" 
...
[16/Nov/2015:10:41:43 -0800] NSACLPlugin - STAR Access allowed on attr:uniqueMember; entry:cn=jcmt-mjlsg14b,ou=admingroups,ou=abc [16/Nov/2015:10:41:43 -0800] NSACLPlugin - conn=57465 op=52 (on attr): Allow read on entry(cn=jcmt-mjlsg14b,ou=admingroups,ou=abc).attr(uniqueMember) to proxy (uid=stmairs,ou=users,ou=abc): cached context/parent allow any attr 

"



-bash-4.1$ rpm -qa | grep 389-ds-base
389-ds-base-libs-1.2.11.15-34.el6_5.x86_64
389-ds-base-debuginfo-1.2.11.15-34.el6_5.x86_64
389-ds-base-1.2.11.15-34.el6_5.x86_64


Thanks,
Adrian



On 11/16/2015 09:34 AM, Mark Reynolds wrote:

On 11/16/2015 12:30 PM, Adrian Damian wrote:

Hello 389 Gurus,

This is a very subtle issue that we are seeing on our LDAP server.
Sometimes, the ACIs return different results for the same search
executed from different clients (a Java client vs. a Python or the
ldapsearch client). More specifically, the Java client does not get
access to attributes that is supposed to see but the Python client
does. What's even more strange is that after the Python client or
ldapsearch client access, the Java client also starts working for a
while and then stops again.

The only difference that we've seen in these two cases in the LDAP
logs is that when it doesn't work, the Java client makes the server
skip the ACI that grants access with the message: "Found READ SKIP in
cache". After running the other clients the ACI in question is
evaluated and everything works for a while before going back into the
bad state.

Any ideas of how to fix this?

Adrian,

Can you provide access log snippets showing the java and python client
searches?

What is the ACI(s) that impacts these searches?

Please get: rpm -qa | grep 389-ds-base

Thanks,
Mark

Thank you,
Adrian

Server version:

389-Directory/1.2.11.15 B2014.219.179

--
389 users mailing list
[email protected]
https://admin.fedoraproject.org/mailman/listinfo/389-users

--
389 users mailing list
[email protected]
https://admin.fedoraproject.org/mailman/listinfo/389-users




--
389 users mailing list
[email protected]
https://admin.fedoraproject.org/mailman/listinfo/389-users





--
389 users mailing list
[email protected]
https://admin.fedoraproject.org/mailman/listinfo/389-users

Reply via email to