Re: Problem with ldapsearch and scope one in 1.4.0.20

[Mark Reynolds <mreynolds@xxxxxxxxxx>]

On 1/24/19 8:37 AM, Mihai Carabas wrote:
> On Thu, Jan 24, 2019 at 12:52 AM William Brown <wbrown@xxxxxxx> wrote:
> > > On 24 Jan 2019, at 00:50, Mihai Carabas <mihai.carabas@xxxxxxxxx> wrote:
> > >
> > > =profesor
> > >         42815 42818 42821 42824 42827 42830 42833 42836 42839 42842
> > > 42845 42848 43445 43450 45720 52253
> > > =profesori
> > >         7 68 3232 3648 5457 6259 6268 6270 6275 6278 6280 6282 6304
> > > 6308 6323 7098 21827
> > Can you also send me the output of :
> >
> > ldapsearch -b …. -s sub ‘(ou=Profesori)’ entryid
> # extended LDIF
> #
> # LDAPv3
> # base <ou=DPPD,ou=People,dc=curs,dc=pub,dc=ro> with scope subtree
> # filter: ou=Profesori
> # requesting: entryid
> #
>
> # Profesori, DPPD, People, curs.pub.ro
> dn: ou=Profesori,ou=DPPD,ou=People,dc=curs,dc=pub,dc=ro
> entryid: 3648
>
> # search result
> search: 2
> result: 0 Success
>
> I issued db2index and I have the following output:
> the 50% threshold.
> [24/Jan/2019:15:14:31.578343786 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Ending pass number 1 ...
> [24/Jan/2019:15:14:31.781708885 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Foreman is done; waiting for workers to finish...
> [24/Jan/2019:15:14:32.055444491 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers finished; cleaning up...
> [24/Jan/2019:15:14:32.259020991 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers cleaned up.
> [24/Jan/2019:15:14:32.262209501 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweeping files for merging
> later...
> [24/Jan/2019:15:14:33.674826562 +0200] - INFO - dblayer_instance_start
> - Import is running with nsslapd-db-private-import-mem on; No other
> process is allowed to access the database
> [24/Jan/2019:15:14:33.975430948 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweep done.
> [24/Jan/2019:15:14:33.982718069 +0200] - INFO - import_main_offline -
> reindex cursdb: Beginning pass number 2
> [24/Jan/2019:15:14:54.035041942 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 204521866.1/sec, recent rate 0.0/sec, hit ratio 0%
>
> [24/Jan/2019:15:15:14.086428912 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 104755102.1/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:15:34.138688984 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 70409167.0/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:15:54.189761953 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 53024187.5/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:16:14.239427918 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 42524348.4/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:16:34.483660956 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 35495530.5/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:16:54.533827623 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 30460703.5/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:17:14.586325096 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 26676765.1/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:17:34.636106261 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 23729056.3/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:17:54.686551928 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 21367956.2/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:18:14.812847819 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 19434204.5/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:18:34.883738846 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 17821407.4/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:18:54.938178725 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 16455782.3/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:19:14.995408557 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 15284552.3/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:19:35.047817446 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 2) -- average rate
> 14221719.2/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:19:35.051470957 +0200] - INFO - import_throw_in_towel
> - reindex cursdb: Decided to end this pass because the progress rate
> has dropped below the 50% threshold.
> [24/Jan/2019:15:19:35.054926468 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Ending pass number 2 ...
> [24/Jan/2019:15:19:35.258101594 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Foreman is done; waiting for workers to finish...
> [24/Jan/2019:15:19:35.261243303 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers finished; cleaning up...
> [24/Jan/2019:15:19:35.464851131 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers cleaned up.
> [24/Jan/2019:15:19:35.467968441 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweeping files for merging
> later...
> [24/Jan/2019:15:19:35.506390559 +0200] - INFO - dblayer_instance_start
> - Import is running with nsslapd-db-private-import-mem on; No other
> process is allowed to access the database
> [24/Jan/2019:15:19:35.731292752 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweep done.
> [24/Jan/2019:15:19:35.734380561 +0200] - INFO - import_main_offline -
> reindex cursdb: Beginning pass number 3
> [24/Jan/2019:15:19:55.782461337 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 214747959.4/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:20:15.834380724 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 107373979.7/sec, recent rate 0.0/sec, hit ratio 0%
>
>
> [24/Jan/2019:15:20:35.886774313 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 71582653.1/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:20:55.938228899 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 53686989.9/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:21:15.988693682 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 42949591.9/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:21:40.661184607 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 34359673.5/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:22:00.820373724 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 29620408.2/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:22:20.872956514 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 26030055.7/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:22:40.928481812 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 23215995.6/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:23:00.983057008 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 20951020.4/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:23:21.398151214 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 19004244.2/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:23:41.466437252 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 17459183.7/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:24:01.517539137 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 16146463.1/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:24:21.568626321 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 15017339.8/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:24:41.726888036 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 3) -- average rate
> 14035814.3/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:24:41.731112549 +0200] - INFO - import_throw_in_towel
> - reindex cursdb: Decided to end this pass because the progress rate
> has dropped below the 50% threshold.
> [24/Jan/2019:15:24:41.734400859 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Ending pass number 3 ...
> [24/Jan/2019:15:24:41.837514477 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Foreman is done; waiting for workers to finish...
> [24/Jan/2019:15:24:41.841081788 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers finished; cleaning up...
> [24/Jan/2019:15:24:41.944805808 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Workers cleaned up.
> [24/Jan/2019:15:24:41.948172218 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweeping files for merging
> later...
> [24/Jan/2019:15:24:41.972718294 +0200] - INFO - dblayer_instance_start
> - Import is running with nsslapd-db-private-import-mem on; No other
> process is allowed to access the database
> [24/Jan/2019:15:24:42.277287032 +0200] - INFO -
> import_sweep_after_pass - reindex cursdb: Sweep done.
> [24/Jan/2019:15:24:42.524714295 +0200] - INFO - import_main_offline -
> reindex cursdb: Beginning pass number 4
> [24/Jan/2019:15:25:02.589790122 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 4) -- average rate
> 214747959.4/sec, recent rate 0.0/sec, hit ratio 0%
> [24/Jan/2019:15:25:22.648607831 +0200] - INFO - import_monitor_threads
> - reindex cursdb: Processed 8108 entries (pass 4) -- average rate
> 107373979.7/sec, recent rate 0.0/sec, hit ratio 0%
>
> And it takes a long time. What should I do?

This is very odd that the index task is not proceeding.  Are there more 
than 8108 entries in the database?  Or is that the size of the db in 
entries?

If the task is still running can you grab a stack traces using this process:

http://www.port389.org/docs/389ds/FAQ/faq.html#debugging-hangs

Grab  a few stack traces with that gdb command, and send them to us please.


Then to fix it I think we need to do an export & import of the 
database.  That will regenerate everything.  If you are using 
replication then use the "--replication" option with db2ldif, otherwise 
do not use that option:

    dsctl <INSTANCE> stop    --->  You might have to kill the process 
if the reindex is hanging :-(

    dsctl <INSTANCE> db2ldif userroot <LDIF file name> --replication

Then import that LDIF

    dsctl <INSTANCE> ldif2db userroot <LDIF file name>

    dsctl <INSTANCE> start


Then retry your search tests.


Regards,

Mark


> > This is not contingent on db2index, so you can run the db2index and see if that corrects the issue now (if you have not already).
> >
> > Thanks
> >
> > —
> > Sincerely,
> >
> > William Brown
> > Software Engineer, 389 Directory Server
> > SUSE Labs
> > _______________________________________________
> > 389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
> > To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> > Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
> > List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> > List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
> _______________________________________________
> 389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
> To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
> Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
> List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
> List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx
_______________________________________________
389-users mailing list -- 389-users@xxxxxxxxxxxxxxxxxxxxxxx
To unsubscribe send an email to 389-users-leave@xxxxxxxxxxxxxxxxxxxxxxx
Fedora Code of Conduct: https://getfedora.org/code-of-conduct.html
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: https://lists.fedoraproject.org/archives/list/389-users@xxxxxxxxxxxxxxxxxxxxxxx