-
Bug
-
Resolution: Done-Errata
-
Minor
-
rhel-8.3.0, rhel-9.3.0
-
389-ds-base-2.5.2-1.el9
-
None
-
Low
-
rhel-sst-idm-ds
-
ssg_idm
-
25
-
0
-
QE ack
-
False
-
-
None
-
None
-
-
Pass
-
Automated
-
Bug Fix
-
-
Done
-
-
Unspecified
-
None
Description of problem:
When run from the test framework, ldif2db is very slow (average : 200 entries/sec for an ldif file containing 12000 entries).
Stangely, ldif2db run from the command line with the same ldif file is much faster (more than 2000 entries/sec)
Version-Release number of selected component (if applicable):
389-ds-base-1.4.3.8-2.module+el8.3.0+6591+ebfc9766.x86_64
How reproducible:
always
Steps to Reproduce:
1.Run automated test dirsrvtests/tests/suites/import/regression_test.py::test_large_ldif2db_ancestorid_index_creation, (changing num_users to 10000 to have faster results) with DEBUGGING=True to keep at the end the generated ldif file
(This test is currently under review as pr/51099)
2.Run ldif2db from the command line, using the ldif file created in the test above :
- ldif2db -n test -i '/var/lib/dirsrv/slapd-standalone1/ldif/large_nested.ldif'
Actual results:
For step 1. (ldif2db started from the test framework) traces in the errors log show a very slow import rate:
[20/May/2020:06:00:25.820924564 -0400] - INFO - bdb_import_main - import test: Import complete. Processed 12047 entries in 62 seconds. (194.31 entries/sec)
For step 2. (ldif2db started from the cli) traces in the errors log show a much faster import rate for the same ldif file :
[20/May/2020:06:03:04.990715437 -0400] - INFO - bdb_import_main - import test: Import complete. Processed 12047 entries in 5 seconds. (2409.40 entries/sec)
Expected results:
Same behavior observed for ldif2db launched from the testframework and from the cli.
Performances shown using ldif2db in the test framework improved to get closer to the ones obtained with the cli
Additional info:
In the 1st case (from test framework), traces in the errors log for the ldif file processing :
[20/May/2020:05:59:24.030003867 -0400] - INFO - import_producer - import test: Processing file "/var/lib/dirsrv/slapd-standalone1/ldif/large_nested.ldif"
[20/May/2020:05:59:44.215667926 -0400] - INFO - import_monitor_threads - import test: Processed 4119 entries – average rate 196.1/sec, recent rate 196.1/sec, hit ratio 0%
[20/May/2020:06:00:04.687489324 -0400] - INFO - import_monitor_threads - import test: Processed 8118 entries – average rate 198.0/sec, recent rate 198.0/sec, hit ratio 100%
[20/May/2020:06:00:24.511326169 -0400] - INFO - import_producer - import test: Finished scanning file "/var/lib/dirsrv/slapd-standalone1/ldif/large_nested.ldif" (12047 entries)
Traces in the 2nd case (from cli)
[20/May/2020:06:02:59.413316634 -0400] - INFO - import_producer - import test: Processing file "/var/lib/dirsrv/slapd-standalone1/ldif/large_nested.ldif"
[20/May/2020:06:03:03.122115784 -0400] - INFO - import_producer - import test: Finished scanning file "/var/lib/dirsrv/slapd-standalone1/ldif/large_nested.ldif" (12047 entries)
- external trackers
- links to
-
RHSA-2024:132195
389-ds-base bug fix and enhancement update
[RHEL-5131] ldif2db can be very slow
============================================= test session starts ==============================================
platform linux -- Python 3.9.19, pytest-6.2.2, py-1.10.0, pluggy-0.13.1 -- /usr/bin/python3
cachedir: .pytest_cache
389-ds-base: 2.5.2-1.el9
nss: 3.90.0-7.el9_4
nspr: 4.35.0-7.el9_4
openldap: 2.6.6-3.el9
cyrus-sasl: not installed
FIPS: disabled
rootdir: /root/ds/dirsrvtests, configfile: pytest.ini
collected 1 item
dirsrvtests/tests/suites/import/regression_test.py::test_ldif2db_after_backend_create PASSED [100%]
============================================== 1 passed in 36.81s ==============================================
Marc Sauton
added a comment - on RHEL-9 and 8, / RHDS-12 and 11, the ldif2db slowness usually happens when either the default import cache or the default entry cache are too small.
if in offline mode, the nsslapd-import-cache-autosize -1 value indicates to allocate 50% of the free RAM to ns-slapd for import, is it possible there was not enough memory to allocate for the data size?
we should have seen an event in the errors log with:
INFO - check_and_set_import_cache - Import allocates xxxxxxKB import cache.
and an output of
free
ls -lh file.ldif
I always have to do this when the LDAP service is up ad running:
dsconf instance-name-here backend config get | grep import
dsconf instance-name-here backend config set --import-cache-autosize=0 --import-cachesize=10737418240 # turn off autosizing and 10GB import cache example
dsconf instance-name-here backend config get | grep import
but there could be some other issues.
Marc Sauton
added a comment - on RHEL-9 and 8, / RHDS-12 and 11, the ldif2db slowness usually happens when either the default import cache or the default entry cache are too small.
if in offline mode, the nsslapd-import-cache-autosize -1 value indicates to allocate 50% of the free RAM to ns-slapd for import, is it possible there was not enough memory to allocate for the data size?
we should have seen an event in the errors log with:
INFO - check_and_set_import_cache - Import allocates xxxxxxKB import cache.
and an output of
free
ls -lh file.ldif
I always have to do this when the LDAP service is up ad running:
dsconf instance-name-here backend config get | grep import
dsconf instance-name-here backend config set --import-cache-autosize=0 --import-cachesize=10737418240 # turn off autosizing and 10GB import cache example
dsconf instance-name-here backend config get | grep import
but there could be some other issues. 
pm-rhel
added a comment - Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.
pm-rhel
added a comment - Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug. https://github.com/389ds/389-ds-base/issues/4432 --> This fixes terrible import performance after a import fails (because the cache size was incorrectly set to zero after the failure), but the issue inside of py.test is still a mystery.
While I still can not figure out why imports are slow in the testing framework, I was able to reproduce very slow imports that appears to be systematic. Here are the steps:
[1] Attempt an import with a typo in the LDIF file name so that the import fails:
- dsconf slapd-localhost backend import userroot 1mil-typo.ldif
[2] Fix the typo and do the import:
- dsconf localhost backend import userroot 1mil.ldif
[02/Nov/2020:16:44:06.244158418 -0500] - INFO - import_monitor_threads - import userroot: Processed 58 entries – average rate 2.9/sec, recent rate 2.9/sec, hit ratio 0%
[02/Nov/2020:16:44:26.281630749 -0500] - INFO - import_monitor_threads - import userroot: Processed 108 entries – average rate 2.7/sec, recent rate 2.7/sec, hit ratio 100%
[02/Nov/2020:16:44:46.314696042 -0500] - INFO - import_monitor_threads - import userroot: Processed 158 entries – average rate 2.6/sec, recent rate 2.5/sec, hit ratio 100%
...
[3] Restart the server, and try the import again:
[02/Nov/2020:16:51:19.259511417 -0500] - INFO - import_monitor_threads - import userroot: Processed 85095 entries – average rate 4254.8/sec, recent rate 4254.7/sec, hit ratio 0%
[02/Nov/2020:16:51:39.516911186 -0500] - INFO - import_monitor_threads - import userroot: Processed 153041 entries – average rate 3825.9/sec, recent rate 3825.9/sec, hit ratio 97%
[02/Nov/2020:16:51:59.708787576 -0500] - INFO - import_monitor_threads - import userroot: Processed 217130 entries – average rate 3618.8/sec, recent rate 3300.9/sec, hit ratio 96%
I can keep reimporting the same LDIF file over and over and the import is fast, but as soon as an import fails all future attempts are really slow until the server is restarted.
Since the problem described in this issue should be resolved in a recent advisory, it has been closed.
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-2024:9164