Hi Florence,
Thanks again for getting back to me! I took another look at this, I was able to re-grab
the LDAP access logs. The issue here is reproducible simply by running 'ipa cert-find
--host=$fqdn', the host doesn't even have to exist. When that runs, from the
389-ds access logs we see this:
[21/Dec/2018:17:13:32.314209537 +0000] conn=19 op=38 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.314371156 +0000] conn=19 op=38 SORT serialno
[21/Dec/2018:17:13:32.314380526 +0000] conn=19 op=38 VLV 0:2147483647:A 9838:9838 (0)
[21/Dec/2018:17:13:32.314521575 +0000] conn=19 op=38 RESULT err=0 tag=101 nentries=1
etime=0.0000383091
[21/Dec/2018:17:13:32.317496089 +0000] conn=19 op=39 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.323799789 +0000] conn=19 op=39 SORT serialno
[21/Dec/2018:17:13:32.323808123 +0000] conn=19 op=39 VLV 0:2147483647:0:9838 1:9838 (0)
[21/Dec/2018:17:13:32.446840192 +0000] conn=19 op=39 RESULT err=4 tag=101 nentries=2000
etime=0.0132104757
[21/Dec/2018:17:13:32.488055654 +0000] conn=19 op=40 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.493148488 +0000] conn=19 op=40 SORT serialno
[21/Dec/2018:17:13:32.493163030 +0000] conn=19 op=40 VLV 0:2147483647:1999:9838 2000:9838
(0)
[21/Dec/2018:17:13:32.601344856 +0000] conn=19 op=40 RESULT err=4 tag=101 nentries=2000
etime=0.0154444399
[21/Dec/2018:17:13:32.665053088 +0000] conn=19 op=41 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.668917938 +0000] conn=19 op=41 SORT serialno
[21/Dec/2018:17:13:32.668928663 +0000] conn=19 op=41 VLV 0:2147483647:3998:9838 3999:9838
(0)
[21/Dec/2018:17:13:32.765771934 +0000] conn=19 op=41 RESULT err=4 tag=101 nentries=2000
etime=0.0164377186
[21/Dec/2018:17:13:32.850446325 +0000] conn=19 op=42 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.854495450 +0000] conn=19 op=42 SORT serialno
[21/Dec/2018:17:13:32.854513780 +0000] conn=19 op=42 VLV 0:2147483647:5997:9838 5998:9838
(0)
[21/Dec/2018:17:13:32.933633117 +0000] conn=19 op=42 RESULT err=4 tag=101 nentries=2000
etime=0.0167819330
[21/Dec/2018:17:13:33.007060840 +0000] conn=19 op=43 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:33.008414443 +0000] conn=19 op=43 SORT serialno
[21/Dec/2018:17:13:33.008424406 +0000] conn=19 op=43 VLV 0:2147483647:7996:9838 7997:9838
(0)
[21/Dec/2018:17:13:33.112973364 +0000] conn=19 op=43 RESULT err=0 tag=101 nentries=1842
etime=0.1820700649
I then went ahead and tried to create an ldapsearch that would reproduce this condition, I
used the following:
ldapsearch -E 'vlv=0/2147483647/0/9838' -E 'sss=serialno' -LLL -o
ldif-wrap=no -D 'cn=Directory Manager' -W -h $(hostname -f) -s one -b
'ou=certificateRepository,ou=ca,o=ipaca' '(certStatus=*)'
And then from the LDAP access logs with that command we se:
[21/Dec/2018:17:12:42.100058456 +0000] conn=162 fd=135 slot=135 connection from
172.16.2.104 to 172.16.2.104
[21/Dec/2018:17:12:42.100331492 +0000] conn=162 op=0 BIND dn="cn=Directory
Manager" method=128 version=3
[21/Dec/2018:17:12:42.100393997 +0000] conn=162 op=0 RESULT err=0 tag=97 nentries=0
etime=0.0000288246 dn="cn=directory manager"
[21/Dec/2018:17:12:42.100511746 +0000] conn=162 op=1 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:12:42.106792071 +0000] conn=162 op=1 SORT serialno
[21/Dec/2018:17:12:42.106800194 +0000] conn=162 op=1 VLV 0:2147483647:0:9838 1:9838 (0)
[21/Dec/2018:17:12:48.563464695 +0000] conn=162 op=1 RESULT err=0 tag=101 nentries=9838
etime=6.1537001563
[21/Dec/2018:17:12:59.836640254 +0000] conn=162 op=-1 fd=135 closed - B1
To call out explicitly, my LDAP search logs:
[21/Dec/2018:17:12:42.100511746 +0000] conn=162 op=1 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:12:42.106792071 +0000] conn=162 op=1 SORT serialno
[21/Dec/2018:17:12:42.106800194 +0000] conn=162 op=1 VLV 0:2147483647:0:9838 1:9838 (0)
[21/Dec/2018:17:12:48.563464695 +0000] conn=162 op=1 RESULT err=0 tag=101 nentries=9838
etime=6.1537001563
and the dogtag one has the same lines:
[21/Dec/2018:17:13:32.317496089 +0000] conn=19 op=39 SRCH
base="ou=certificateRepository,ou=ca,o=ipaca" scope=1
filter="(certStatus=*)" attrs=ALL
[21/Dec/2018:17:13:32.323799789 +0000] conn=19 op=39 SORT serialno
[21/Dec/2018:17:13:32.323808123 +0000] conn=19 op=39 VLV 0:2147483647:0:9838 1:9838 (0)
[21/Dec/2018:17:13:32.446840192 +0000] conn=19 op=39 RESULT err=4 tag=101 nentries=2000
etime=0.0132104757
However, it seems like the dogtag one, has an nentries=2000, unlike mine, which returns
everything, even though the VLV line is the same (maybe 389-ds doesn't log everything
for the request?)
As for the Dogtag code, I can only find one use of 'LDAPVirtualListControl' and
that's in
https://github.com/dogtagpki/pki/blob/DOGTAG_10_5_1_FEDORA_27/base/server...
The only piece of the Dogtag code that stands out to me is 'mMaxReturns' set to
2000 here
https://github.com/dogtagpki/pki/blob/DOGTAG_10_5_1_FEDORA_27/base/server....
It looks like it does try to read that in from some config via,
https://github.com/dogtagpki/pki/blob/DOGTAG_10_5_1_FEDORA_27/base/server...
but, I can't figure out where that would be or how to set it.
Anyway, that's about as far as I've gotten today. If you or anyone on this list is
more familiar with the Dogtag codebase and sees something I'm missing. Please let me
know, more than happy to throw anything at the wall and see what sticks as the host
cleanup in production that we're running is going to go for a few weeks at this speed.
Thanks again,
Jared