search

389ds / 389-ds-base

The enterprise-class Open Source LDAP server for Linux
https://www.port389.org/
Other
211 stars 91 forks source link

nsRoles doesn't seem to be cached for a slapd instance that has been running for a long period of time #5695

Open e-resnick opened 1 year ago

e-resnick commented 1 year ago

I have a slapd installation installed from a RHDS 11 installation. slapd is running for a number of days - queries using a filter based on nsRole take a VERY long time to complete and most software tools timeout before the search is completed. Running ldapsearch locally on the server completes finally (see below) and then the searches with nsRole filter complete in a timely fashion. After a restart of slapd this process needs to be manually done once again for the applications to work properly. I understand that nsRole is supposed to be cached after ~4 minutes - why is this not happening?

1st run: SRCH base="dc=example,dc=com" scope=2 filter="(&(nsRole=cn=NSROLE,dc=example,dc=com)(objectClass=USER))" attrs="distinguishedName " RESULT err=0 tag=101 nentries=11 wtime=0.000070735 optime=179.484774853 etime=179.484840590 notes=A details="Fully Unindexed Filter"

Following queries SRCH base="dc=example,dc=com" scope=2 filter="(&(nsRole=cn=NSROLE,dc=example,dc=com)(objectClass=USER))" attrs="distinguishedName" RESULT err=0 tag=101 nentries=11 wtime=0.000060507 optime=0.558663030 etime=0.558718327 notes=A details="Fully Unindexed Filter

droideck commented 1 year ago

Looking at the ldap/servers/plugins/roles/roles_cache.c and ldap/servers/plugins/roles/roles_plugin.c code, I'm not sure it builds roles cache on the instance start-up. But fix me if I missed it somewhere.

Also, it's possible that it takes too long or it's blocked somewhere on the way.

If you (or your customer) have a testing environment, could you please test the next scenario? (on non-production env, of course, - as it may disturb the downtime):

  1. Stop the instance;
  2. Enable plugin logging via dse.ldif;
  3. Start the instance;
  4. Let it work for some time (half an hour, at least);
  5. Run the nsRole search;
  6. Extract the logs: grep "roles-plugin" /var/log/dirsrv/slapd_INSTANCE/errors > roles_logging.txt

Looking at the logs, we may better pinpoint the issue.

progier389 commented 1 year ago

I wonder if the problem is really related to the nsrole cache: As the search is unindexed, the filters are evaluated and I would rather suspect the dn normalization cache. You can easily check that by doing an ldapsearch objectclass=* before querying the nsrole IMHO using some perf tools like "perf c2c" may also help to understand whats happen

e-resnick commented 1 year ago 
body p { margin-bottom: 0cm; margin-top: 0pt; } 

Can you please expand on how to monitor
  this issue like how to run the perf tool example below?
  Eddy

On 15/03/2023 15:10, progier389 wrote:

  I wonder if the problem is really related to the
    nsrole cache:
    As the search is unindexed, the filters are evaluated and I
    would rather suspect the dn normalization cache.
    You can easily check that by doing an ldapsearch objectclass=*
    before querying the nsrole
    IMHO using some perf tools like "perf c2c" may also help to
    understand whats happen
  —
    Reply to this email directly, view it on GitHub, or unsubscribe.
    You are receiving this because you authored the thread.Message
      ID: ***@***.***>
  [

{ @.": "http://schema.org", @.": "EmailMessage", "potentialAction": { @.": "ViewAction", "target": "https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1469983367", "url": "https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1469983367", "name": "View Issue" }, "description": "View this Issue on GitHub", "publisher": { @.": "Organization", "name": "GitHub", "url": "https://github.com" } } ]

progier389 commented 1 year ago

The /usr/bin/perf tools is in the "perf" package and tbordaz has put some instruction about using it in https://www.port389.org/docs/389ds/development/performance-diagnostic.html#cache-alignment-of-hot-structure For my part what I found the most useful in the report is not the summary table as shown in tbordaz's page but the calling graphs sorted by decreasing contention rate that is in the last section of the report. For example:

    129      310        12  [.] pthread_rwlock_unlock@@GLI  libc.so.6  pthread_rwlock_unlock@@GLIBC_2   0
            |
            ---___pthread_rwlock_unlock (inlined)
               slapi_rwlock_unlock
               |          
               |--27.35%--attr_syntax_get_by_name_locking_optional
               |          |          
               |          |--19.16%--slapi_attr_init_locking_optional
               |          |          |          
               |          |          |--15.22%--slapi_attr_init
               |          |          |          entry_attr_init (inlined)
               |          |          |          str2entry_dupcheck
               |          |          |          
               |          |           --3.93%--attrlist_find_or_create_locking_optional
               |          |                     attrlist_find_or_create
               |          |                     |          
               |          |                     |--2.34%--attrlist_merge_valuearray
               |          |                     |          slapi_entry_attr_merge_sv
               |          |                     |          slapi_entry_attr_merge
               |          |                     |          slapi_entry_attr_replace
               |          |                     |          |          
               |          |                     |          |--2.34%--dbmdb_import_add_created_attrs (inlined)
               |          |                     |          |          dbmdb_import_prepare_worker_entry
               |          |                     |          |          dbmdb_import_worker
               |          |                     |          |          0x7f20f2e8e412
               |          |                     |          |          start_thread
               |          |                     |          |          __clone3 (inlined)
               |          |                     |          |          
               |          |                     |           --0.00%--slapi_entry_attr_set_charptr
               |          |                     |                     slapi_entry_set_uniqueid
               |          |                     |                     dbmdb_import_generate_uniqueid
               |          |                     |                     dbmdb_import_prepare_worker_entry
               |          |                     |                     dbmdb_import_worker
               |          |                     |                     0x7f20f2e8e412
               |          |                     |                     start_thread
               |          |                     |                     __clone3 (inlined)
               |          |                     |          
               |          |                     |--1.59%--attrlist_replace
               |          |                     |          entry_replace_values
               |          |                     |          add_update_entry_operational_attributes
               |          |                     |          dbmdb_add_op_attrs
               |          |                     |          process_entryrdn (inlined)
               |          |                     |          dbmdb_import_worker
               |          |                     |          0x7f20f2e8e412
               |          |                     |          start_thread
               |          |                     |          __clone3 (inlined)
               |          |                     |          
               |          |                      --0.00%--attrlist_replace_with_flags
               |          |                                entry_replace_values_with_flags
               |          |                                add_update_entrydn_operational_attributes
               |          |                                add_update_entry_operational_attributes
               |          |                                dbmdb_add_op_attrs
               |          |                                process_entryrdn (inlined)
               |          |                                dbmdb_import_worker
               |          |                                0x7f20f2e8e412
               |          |                                start_thread
               |          |                                __clone3 (inlined)
               |          |          
               |           --8.19%--attr_syntax_get_by_name
               |                     |          
               |                     |--8.19%--slapi_attr_is_dn_syntax_type
               |                     |          slapi_dn_normalize_ext
               |                     |          |          
               |                     |          |--7.52%--slapi_sdn_get_dn
               |                     |          |          |          
               |                     |          |          |--4.11%--slapi_sdn_get_ndn
               |                     |          |          |          dbmdb_import_entry_info
               |                     |          |          |          dbmdb_import_producer
               |                     |          |          |          0x7f20f2e8e412
               |                     |          |          |          start_thread
               |                     |          |          |          __clone3 (inlined)
               |                     |          |          |          
               |                     |          |          |--2.59%--value_dn_normalize_value
               |                     |          |          |          valuearray_dn_normalize_value
               |                     |          |          |          attrlist_replace_with_flags
               |                     |          |          |          entry_replace_values_with_flags
               |                     |          |          |          add_update_entrydn_operational_attributes
               |                     |          |          |          add_update_entry_operational_attributes
               |                     |          |          |          dbmdb_add_op_attrs
               |                     |          |          |          process_entryrdn (inlined)
               |                     |          |          |          dbmdb_import_worker
               |                     |          |          |          0x7f20f2e8e412
               |                     |          |          |          start_thread
               |                     |          |          |          __clone3 (inlined)
               |                     |          |          |          
               |                     |          |           --0.82%--_slapi_rdn_init_all_dn_ext
               |                     |          |                     slapi_rdn_init_all_dn
               |                     |          |                     slapi_rdn_set_all_dn
               |                     |          |                     slapi_entry_set_rdn
               |                     |          |                     str2entry_dupcheck
               |                     |          |          
               |                     |           --0.67%--slapi_create_dn_string
               |                     |                     dbmdb_import_prepare_worker_entry
               |                     |                     dbmdb_import_worker
               |                     |                     0x7f20f2e8e412
               |                     |                     start_thread
               |                     |                     __clone3 (inlined)
               |                     |          
               |                      --0.00%--slapi_attr_syntax_normalize
               |                                slapi_entry_add_rdn_values
               |                                str2entry_dupcheck
               |          
               |--19.26%--attr_syntax_return_locking_optional
               |          |          
               |          |--18.72%--slapi_attr_init_locking_optional
               |          |          |          
               |          |          |--13.52%--slapi_attr_init
               |          |          |          entry_attr_init (inlined)
               |          |          |          str2entry_dupcheck
               |          |          |          
               |          |           --5.20%--attrlist_find_or_create_locking_optional
               |          |                     attrlist_find_or_create
               |          |                     |          
               |          |                     |--2.83%--attrlist_merge_valuearray
               |          |                     |          slapi_entry_attr_merge_sv
               |          |                     |          slapi_entry_attr_merge
               |          |                     |          slapi_entry_attr_replace
               |          |                     |          |          
               |          |                     |          |--2.10%--dbmdb_import_add_created_attrs (inlined)
               |          |                     |          |          dbmdb_import_prepare_worker_entry
               |          |                     |          |          dbmdb_import_worker
               |          |                     |          |          0x7f20f2e8e412
               |          |                     |          |          start_thread
               |          |                     |          |          __clone3 (inlined)
               |          |                     |          |          
               |          |                     |           --0.73%--slapi_entry_attr_set_charptr
               |          |                     |                     slapi_entry_set_uniqueid
               |          |                     |                     dbmdb_import_generate_uniqueid
               |          |                     |                     dbmdb_import_prepare_worker_entry
               |          |                     |                     dbmdb_import_worker
               |          |                     |                     0x7f20f2e8e412
               |          |                     |                     start_thread
               |          |                     |                     __clone3 (inlined)
               |          |                     |          
               |          |                     |--2.37%--attrlist_replace
               |          |                     |          entry_replace_values
               |          |                     |          add_update_entry_operational_attributes
               |          |                     |          dbmdb_add_op_attrs
               |          |                     |          process_entryrdn (inlined)
               |          |                     |          dbmdb_import_worker
               |          |                     |          0x7f20f2e8e412
               |          |                     |          start_thread
               |          |                     |          __clone3 (inlined)
               |          |                     |          
               |          |                      --0.00%--attrlist_replace_with_flags
               |          |                                entry_replace_values_with_flags
               |          |                                add_update_entrydn_operational_attributes
               |          |                                add_update_entry_operational_attributes
               |          |                                dbmdb_add_op_attrs
               |          |                                process_entryrdn (inlined)
               |          |                                dbmdb_import_worker
               |          |                                0x7f20f2e8e412
               |          |                                start_thread
               |          |                                __clone3 (inlined)
               |          |          
               |           --0.54%--attr_syntax_return
               |                     slapi_attr_syntax_normalize
               |                     slapi_entry_add_rdn_values
               |                     str2entry_dupcheck
               |          
                --1.01%--attr_syntax_unlock_read
                          str2entry_dupcheck

           0.00%    1.92%   50.37%    0.00%                 0x0     0       1      0x7f20f32925ca         0       427   
    184      321        12  [.] pthread_rwlock_rdlock@GLIB  libc.so.6  pthread_rwlock_rdlock@GLIBC_2.   0
e-resnick commented 1 year ago

So what does it mean " nsRoleFilter is disabled"? Is this the source of the nsRole slowness?

ERR - roles-plugin - roles_cache_create_object_from_entry - "cn=scdynbnhpmanagersprd_old,dc=bnhpgroup,dc=com": not allowed to use "nsrole" in the role filter "(&(objectClass=bnhpUser)(misparbank=012)(kodchasima=0)(|(bnhptitlekey=0307)(bnhptitlekey=0358)(bnhptitlekey=0360)(bnhptitlekey=0494)(bnhptitlekey=0830)(bnhptitlekey=0840)(bnhptitlekey=0845)(bnhptitlekey=0846)(bnhptitlekey=0854)(bnhptitlekey=0855))(!(nsrole=cn=NOscdynbnhpmanagersprd,dc=bnhpgroup,dc=com)))". nsRoleFilter is disabled.

On Tue, Mar 14, 2023 at 8:04 PM Simon Pichugin @.***> wrote:

Looking at the ldap/servers/plugins/roles/roles_cache.c https://github.com/389ds/389-ds-base/blob/7efbeb3b75a5f879dec87a90ff925b436216c4e6/ldap/servers/plugins/roles/roles_cache.c and ldap/servers/plugins/roles/roles_plugin.c https://github.com/389ds/389-ds-base/blob/7efbeb3b75a5f879dec87a90ff925b436216c4e6/ldap/servers/plugins/roles/roles_plugin.c code, I'm not sure it builds roles cache on the instance start-up. But fix me if I missed it somewhere.

Also, it's possible that it takes too long or it's blocked somewhere on the way.

If you (or your customer) have a testing environment, could you please test the next scenario? (on non-production env, of course, - as it may disturb the downtime):

  1. Stop the instance;
  2. Enable plugin logging via dse.ldif;
  3. Start the instance;
  4. Let it work for some time (half an hour, at least);
  5. Run the nsRole search;
  6. Extract the logs: grep "roles-plugin" /var/log/dirsrv/slapd_INSTANCE/errors > roles_logging.txt

Looking at the logs, we may better pinpoint the issue.

— Reply to this email directly, view it on GitHub https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1468583994, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXZOIN5HAUKRH4QBZFKUF5DW4CXKPANCNFSM6AAAAAAV2T7UXQ . You are receiving this because you authored the thread.Message ID: @.***>

mreynolds389 commented 1 year ago

@e-resnick you can not use the attribute "nsRole" in the role filter.

e-resnick commented 1 year ago

Please explain further. These are existing ldap filters that the customer has used in DSEE. They eventually complete - especially after the first such filter has completed. I don't think that we are going to get a welcome answer if I tell them that they need to rewrite code :-(

On Tue, Mar 21, 2023 at 10:07 PM Mark Reynolds @.***> wrote:

@e-resnick https://github.com/e-resnick you can not use the attribute "nsRole" in the role filter.

— Reply to this email directly, view it on GitHub https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1478514395, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXZOIN4RVZNUQUTALT77HWDW5IC6JANCNFSM6AAAAAAV2T7UXQ . You are receiving this because you were mentioned.Message ID: @.***>

mreynolds389 commented 1 year ago

Please explain further. These are existing ldap filters that the customer has used in DSEE. They eventually complete - especially after the first such filter has completed. I don't think that we are going to get a welcome answer if I tell them that they need to rewrite code :-( … On Tue, Mar 21, 2023 at 10:07 PM Mark Reynolds @.> wrote: @e-resnick https://github.com/e-resnick you can not use the attribute "nsRole" in the role filter. — Reply to this email directly, view it on GitHub <#5695 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXZOIN4RVZNUQUTALT77HWDW5IC6JANCNFSM6AAAAAAV2T7UXQ . You are receiving this because you were mentioned.Message ID: @.>

https://access.redhat.com/documentation/en-us/red_hat_directory_server/11/html/administration_guide/advanced_entry_management-using_roles#creating_a_filtered_role

If you created a filtered role, you can not use nsRole in that filter(nsRoleFilter). The code is very explicit about this. Also you should not compare DSEE to 389 DS - they are different products and should not be expected to work the same way.

Now you can use nsRole in search filters, but you can not use nsRole in a filtered role configuration (nsRoleFilter).

e-resnick commented 1 year ago

Mark. Excuse my ignorance, but I'm still not clear what this means.

I have the following search: ldapsearch -x -D "cn=DIRMGR" -w "PASSWORD" -p 389 -h localhost -b "dc=example,dc=com" "(&(nsrole=cn=ADMIN,dc=example,dc=com)(objectClass=bnhpuser))" dn

If I change the filter to stolen then it completes in about 1 minute (not great but better than FOREVER). Can you please explain to me what is going on?

On Tue, Mar 21, 2023 at 10:07 PM Mark Reynolds @.***> wrote:

@e-resnick https://github.com/e-resnick you can not use the attribute "nsRole" in the role filter.

— Reply to this email directly, view it on GitHub https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1478514395, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXZOIN4RVZNUQUTALT77HWDW5IC6JANCNFSM6AAAAAAV2T7UXQ . You are receiving this because you were mentioned.Message ID: @.***>

e-resnick commented 1 year ago

On the test RHDS 11 environment the similar query works as expected. What could be the difference between the instances (they were both configured in the same fashion but the data is a little different).

On Sun, Mar 26, 2023 at 1:15 PM Edward Resnick @.***> wrote:

Mark. Excuse my ignorance, but I'm still not clear what this means.

I have the following search: ldapsearch -x -D "cn=DIRMGR" -w "PASSWORD" -p 389 -h localhost -b "dc=example,dc=com" "(&(nsrole=cn=AMIDMGroupManageAdminAllUsersPRD,dc=example,dc=com)(objectClass=bnhpuser))" dn

  • it takes FOREVER.

If I change the filter to stolen then it completes in about 1 minute (not great but better than FOREVER). Can you please explain to me what is going on?

On Tue, Mar 21, 2023 at 10:07 PM Mark Reynolds @.***> wrote:

@e-resnick https://github.com/e-resnick you can not use the attribute "nsRole" in the role filter.

— Reply to this email directly, view it on GitHub https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1478514395, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXZOIN4RVZNUQUTALT77HWDW5IC6JANCNFSM6AAAAAAV2T7UXQ . You are receiving this because you were mentioned.Message ID: @.***>

mreynolds389 commented 1 year ago

Ok so far we've been guessing at what you are doing. I think you need to provide a reproducer. Please share the roles configuration you are using so we can look at it. There seems to be some misunderstanding and confusion, between all of us, about what is going on.

So if you can provide, step by step, how the server is configured, the exact searches, how the entries look, etc, that would be very helpful. Thanks Eddy!

e-resnick commented 1 year ago 
body p { margin-bottom: 0cm; margin-top: 0pt; } 

Mark.
  This seems to have been an issue with the DN cache.
  With assistance from Teko Mihinto I ran the dsconf monitor dbmon command and then he
  identified the following dsconf settings:
backend config set --cache-autosize=50

config replace nsslapd-ndn-cache-max-size=2097152000 backend config set --idlistscanlimit=100000

Restarted the instance and then the improved cache performance was able to provide the expected performance on these calls.

I'll be adding a few RFEs around this issue form my experience ;-) Sincerely. Eddy

On 28/03/2023 3:43, Mark Reynolds
  wrote:

  Ok so far we've been guessing at what you are doing.
    I think you need to provide a reproducer. Please share the roles
    configuration you are using so we can look at it. There seems to
    be some misunderstanding and confusion, between all of us, about
    what is going on.
  So if you can provide, step by step, how the server
    is configured, the exact searches, how the entries look, etc,
    that would be very helpful. Thanks Eddy!
  —
    Reply to this email directly, view it on GitHub, or unsubscribe.
    You are receiving this because you were mentioned.Message
      ID: ***@***.***>
  [

{ @.": "http://schema.org", @.": "EmailMessage", "potentialAction": { @.": "ViewAction", "target": "https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1486048406", "url": "https://github.com/389ds/389-ds-base/issues/5695#issuecomment-1486048406", "name": "View Issue" }, "description": "View this Issue on GitHub", "publisher": { @.": "Organization", "name": "GitHub", "url": "https://github.com" } } ]

tmihinto commented 1 year ago

Before adjusting the cache settings, the dbmon output was showing undersized DB and NDN caches:

Database Cache:

Normalized DN Cache: