Description
Issue Description
The following tests fails frequently. In the first one, the access log was checked before it's written and it failed to find an expected word in it. In the second one, some multiple threads have the same file descriptor to write access log, and those ones write it with their own timing. There is no guarantee that the log for the earlier queries are written into the log files earlier. Adding sleep mitigates this failure.
- dirsrvtests/tests/suites/healthcheck/health_config_test.py::test_healthcheck_notes_unindexed_search
- dirsrvtests/tests/suites/paged_results/paged_results_test.py::test_multi_suffix_search
Package Version and Platform:
- Package and version: 389-ds-base-2.2.4-8.el9_2.x86_64 and 389-ds-base-2.5.1-1.el9.x86_64
Steps to Reproduce
- py.test -v dirsrvtests/tests/suites/healthcheck/health_config_test.py::test_healthcheck_notes_unindexed_search
- py.test -v dirsrvtests/tests/suites/paged_results/paged_results_test.py::test_multi_suffix_search
Expected results
Tests passed successfully with higher probability
Additional context
Access Log from the second test (test_multi_suffix_search):
# cat /var/log/dirsrv/slapd-standalone1/access |grep cookie
[11/Jul/2024:10:18:46.798464473 -0400] conn=1 op=63 RESULT err=0 tag=101 nentries=4 wtime=0.000050861 optime=0.001933251 etime=0.001982161 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=0
[11/Jul/2024:10:18:46.806845399 -0400] conn=1 op=66 RESULT err=0 tag=101 nentries=4 wtime=0.000041498 optime=0.002442879 etime=0.002482475 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=0
[11/Jul/2024:10:18:46.813039784 -0400] conn=1 op=67 RESULT err=0 tag=101 nentries=2 wtime=0.000034341 optime=0.004714516 etime=0.004746569 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=-1
[11/Jul/2024:10:18:46.800891409 -0400] conn=1 op=64 RESULT err=0 tag=101 nentries=2 wtime=0.000044929 optime=0.002472561 etime=0.002516322 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=0
[11/Jul/2024:10:18:46.803033964 -0400] conn=1 op=65 RESULT err=0 tag=101 nentries=4 wtime=0.000044943 optime=0.002182204 etime=0.002225282 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=0
[11/Jul/2024:10:18:46.796576171 -0400] conn=1 op=62 RESULT err=0 tag=101 nentries=4 wtime=0.000058250 optime=0.002272217 etime=0.002328974 notes=U,P details="Partially Unindexed Filter,Paged Search" pr_idx=0 pr_cookie=0
The op= numbers in this log are out of order.