Bug 1951020

Summary: Internal unindexed searches in syncrepl
Product: Red Hat Enterprise Linux 8 Reporter: thierry bordaz <tbordaz>
Component: 389-ds-baseAssignee: mreynolds
Status: CLOSED ERRATA QA Contact: RHDS QE <ds-qe-bugs>
Severity: unspecified Docs Contact: Petr Hybl <phybl>
Priority: unspecified    
Version: 8.3CC: ldap-maint, mreynolds, phybl, sgouvern
Target Milestone: betaKeywords: Triaged, ZStream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: sync-to-jira
Fixed In Version: 389-ds-1.4-8050020210715192621.1a75f91c Doc Type: Bug Fix
Doc Text:
.The database indexes created by plug-ins are now enabled Previously, when a server plug-in created its own database indexes, you had to enable those indexes manually. With this update, the indexes are enabled immediately after creation by default.
Story Points: ---
Clone Of:
: 1983095 1993263 2005399 (view as bug list) Environment:
Last Closed: 2021-11-09 18:11:20 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1983095, 1993263, 2005399    

Description thierry bordaz 2021-04-19 12:20:33 UTC
Description of problem:
 I see plenty of complains about partial unindexed searches from syncrepl plugin even though there are indexes defined for the attributes specified in the filter

[15/Nov/2020:18:58:04.118737200 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=72)(targetuniqueid=cb0ce98a-279a11eb-b8b0c9d4-8de4b180))" etime=0.002251050 nentries=1  notes=U details="Partially Unindexed Filter"
[15/Nov/2020:18:58:04.136015700 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=73)(targetuniqueid=cb0ce98a-279a11eb-b8b0c9d4-8de4b180))" etime=0.002381400 nentries=1  notes=U details="Partially Unindexed Filter"
[15/Nov/2020:18:58:04.167502775 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=74)(targetuniqueid=cb0ce98a-279a11eb-b8b0c9d4-8de4b180))" etime=0.000606675 nentries=1  notes=U details="Partially Unindexed Filter"
[15/Nov/2020:18:58:04.187813900 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=74)(targetuniqueid=cb0ce98a-279a11eb-b8b0c9d4-8de4b180))" etime=0.000362425 nentries=1  notes=U details="Partially Unindexed Filter"
[15/Nov/2020:18:58:04.225106850 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=75)(targetuniqueid=cb0ce986-279a11eb-b8b0c9d4-8de4b180))" etime=0.001161925 nentries=1  notes=U details="Partially Unindexed Filter"
[15/Nov/2020:18:58:04.228923925 -0500] - ERR - log_result - Internal unindexed search: source (cn=server,cn=plugins,cn=config) search base="cn=changelog" filter="(&(changenumber>=75)(targetuniqueid=cb0ce986-279a11eb-b8b0c9d4-8de4b180))" etime=0.002395775 nentries=1  notes=U details="Partially Unindexed Filter"



Version-Release number of selected component (if applicable):
I think it exists since 1.4.3.1 (8.3)
9327a3328 Ticket 50727 - correct mistaken options in filter validation patch


How reproducible:
Should be systematic.
See upstream tickets https://github.com/389ds/389-ds-base/issues/4443


Steps to Reproduce:

Actual results:
Error in errors logs "Partially Unindexed Filter" and possibly (TBC) partial results 

Expected results:
Sync repl should not trigger those messages/partial results

Additional info:

Comment 6 sgouvern 2021-07-23 09:57:39 UTC
============================================================ test session starts =============================================================
platform linux -- Python 3.6.8, pytest-6.2.4, py-1.10.0, pluggy-0.13.1 -- /usr/bin/python3.6
cachedir: .pytest_cache
metadata: {'Python': '3.6.8', 'Platform': 'Linux-4.18.0-321.el8.x86_64-x86_64-with-redhat-8.5-Ootpa', 'Packages': {'pytest': '6.2.4', 'py': '1.10.0', 'pluggy': '0.13.1'}, 'Plugins': {'metadata': '1.11.0', 'html': '3.1.1', 'libfaketime': '0.1.2', 'flaky': '3.7.0'}}
389-ds-base: 1.4.3.23-6.module+el8.5.0+11842+2f4233e8
nss: 3.53.1-17.el8_3
nspr: 4.25.0-2.el8_2
openldap: 2.4.46-17.el8
cyrus-sasl: 2.1.27-5.el8
FIPS: disabled
rootdir: /mnt/tests/rhds/tests/upstream/ds/dirsrvtests, configfile: pytest.ini
plugins: metadata-1.11.0, html-3.1.1, libfaketime-0.1.2, flaky-3.7.0
collected 1 item                                                                                                                             

dirsrvtests/tests/suites/retrocl/retrocl_indexing_test.py::test_indexing_is_online PASSED                                              [100%]

============================================================== warnings summary ==============================================================
tests/suites/retrocl/retrocl_indexing_test.py::test_indexing_is_online
tests/suites/retrocl/retrocl_indexing_test.py::test_indexing_is_online
  /mnt/tests/rhds/tests/upstream/ds/src/lib389/lib389/__init__.py:136: DeprecationWarning: Use of raw ldap function search_ext_s. This will be removed in a future release. Found in: /mnt/tests/rhds/tests/upstream/ds/src/lib389/lib389/_mapped_object.py:1267
    "Found in: %s:%s" % (name, frame.filename, frame.lineno)))

-- Docs: https://docs.pytest.org/en/stable/warnings.html
======================================================= 1 passed, 2 warnings in 15.85s =======================================================



Too 
Content Synchronization and Retro Changelog Plugin being enabled
running :
# ldapsearch -D "cn=directory manager" -WWW -LLL -b "dc=example,dc=com" -E sync=rp/"localhost.localdomain:389#cn=directory manager:dc=example,dc=com:(objectClass=*)#1"

didn't produce any ERR message in the errors log


marking as verified:tested

Comment 9 sgouvern 2021-07-23 16:33:14 UTC
As per comment 6 marking as VERIFIED

Comment 13 Petr Hybl 2021-11-04 11:12:27 UTC
Hi, can you please check if the doc text is okay?

Comment 14 mreynolds 2021-11-04 13:11:25 UTC
(In reply to Petr Hybl from comment #13)
> Hi, can you please check if the doc text is okay?

Sorry I find it a bit confusing.  Perhaps this is better?

.The database indexes created by plugins are now enabled.
Previously when a server plugin created its own database indexes, those indexes were not enabled. Those indexes are now enabled immediately after creation.

Comment 16 errata-xmlrpc 2021-11-09 18:11:20 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (389-ds-base bug fix and enhancement update), and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2021:4203