I have Perl script that implements a syncrepl listener using the
listen_for_changes method from Net::LDAPapi (3.0.3). The listener works
well with OpenLDAP 2.4.40 but I am having trouble getting it to work
consistently with 2.4.42.
The code looks something like this:
# $LDAP is bound using GSSAPI
my $msgid = $LDAP->listen_for_changes(
-basedn => "cn=accesslog",
-scope => LDAP_SCOPE_SUBTREE,
-filter => "objectclass=*",
-cookie => "/var/run/sync.cookie");
while (1) {
my @entries;
while (@entries = $LDAP->next_changed_entries($msgid, 0, -1))) {
...
}
Most of the time (but not _all_ of the time) the listener fails to pick
up any entries from the accesslog and I see these messages in my logs:
2015-09-09T08:32:20.926931-07:00 ldap-jessie0 slapd[631]: conn=1161 op=4
SEARCH RESULT tag=101 err=2 nentries=0 text=Sync control : mode decoding
error
2015-09-09T08:32:20.927211-07:00 ldap-jessie0 slapd[631]: conn=1161 op=4
do_search: get_ctrls failed
(Fuller log output included below).
I know that the credentials can read the access log as I run a simple
search against cn=accesslog before the list_for_changes just to be sure
the issue is not related to my credentials.
What does "Sync control : mode decoding error" mean? Any suggestions on
next steps for troubleshooting?
####################################################################
2015-09-09T08:32:20.902032-07:00 ldap-jessie0 slapd[631]: conn=1161
fd=14 ACCEPT from IP=171.67.214.66:39646 (IP=0.0.0.0:389)
2015-09-09T08:32:20.902108-07:00 ldap-jessie0 slapd[631]: conn=1161 op=0
SRCH base="" scope=0 deref=0 filter="(objectClass=*)"
2015-09-09T08:32:20.902207-07:00 ldap-jessie0 slapd[631]: conn=1161 op=0
SRCH attr=supportedSASLMechanisms
2015-09-09T08:32:20.902262-07:00 ldap-jessie0 slapd[631]: conn=1161 op=0
SEARCH RESULT tag=101 err=0 nentries=1 text=
2015-09-09T08:32:20.910842-07:00 ldap-jessie0 slapd[631]: conn=1161 op=1
BIND dn="" method=163
2015-09-09T08:32:20.914261-07:00 ldap-jessie0 slapd[631]: conn=1161 op=1
RESULT tag=97 err=14 text=SASL(0): successful result: mech EXTERNAL is
too weak
2015-09-09T08:32:20.917754-07:00 ldap-jessie0 slapd[631]: conn=1161 op=2
BIND dn="" method=163
2015-09-09T08:32:20.917798-07:00 ldap-jessie0 slapd[631]: conn=1161 op=2
RESULT tag=97 err=14 text=SASL(0): successful result: mech EXTERNAL is
too weak
2015-09-09T08:32:20.918060-07:00 ldap-jessie0 slapd[631]: conn=1161 op=3
BIND dn="" method=163
2015-09-09T08:32:20.918102-07:00 ldap-jessie0 slapd[631]: conn=1161 op=3
BIND authcid="service/ldap-jessie0(a)stanford.edu"
authzid="service/ldap-jessie0(a)stanford.edu"
2015-09-09T08:32:20.918188-07:00 ldap-jessie0 slapd[631]: conn=1161 op=3
BIND dn="cn=ldap-jessie0,cn=service,cn=applications,dc=stanford,dc=edu"
mech=GSSAPI sasl_ssf=56 ssf=56
2015-09-09T08:32:20.918240-07:00 ldap-jessie0 slapd[631]: conn=1161 op=3
RESULT tag=97 err=0 text=
2015-09-09T08:32:20.926931-07:00 ldap-jessie0 slapd[631]: conn=1161 op=4
SEARCH RESULT tag=101 err=2 nentries=0 text=Sync control : mode decoding
error
2015-09-09T08:32:20.927211-07:00 ldap-jessie0 slapd[631]: conn=1161 op=4
do_search: get_ctrls failed