[Date Prev][Date Next] [Chronological] [Thread] [Top]

Troubleshooting syncrepl



I've set up a pair of OpenLDAP servers to work with, so that I can
figure out my SSL problem without worrying about breaking my
currently-working LDAP server.  I got the producer up and running in
about two minutes.  I expected to get the consumer up just as fast, but
ran into a problem... the sunchronization isn't succeeding.  So I
started logging and got:

Consumer:

Jul 30 08:55:32 unix-services2 slapd[8041]: slapd starting
Jul 30 08:55:32 unix-services2 slapd[8041]: daemon: added 4r
Jul 30 08:55:32 unix-services2 slapd[8041]: daemon: added 7r
Jul 30 08:55:32 unix-services2 slapd[8041]: daemon: select: listen=7
active_threads=0 tvp=zero
Jul 30 08:55:32 unix-services2 slapd[8041]: =>do_syncrepl
Jul 30 08:55:32 unix-services2 slapd[8041]: do_syncrep1:
ldap_sasl_bind_s failed (49)
Jul 30 08:55:32 unix-services2 slapd[8041]: daemon: shutdown requested
and initiated.
Jul 30 08:55:32 unix-services2 slapd[8041]: daemon: closing 7
Jul 30 08:55:32 unix-services2 slapd[8041]: slapd shutdown: waiting for
0 threads to terminate


Producer:

Jul 30 08:55:18 test1 slapd[4919]: connection_get(13)
Jul 30 08:55:18 test1 slapd[4919]: connection_get(13): got connid=0
Jul 30 08:55:18 test1 slapd[4919]: connection_read(13): checking for
input on id=0
Jul 30 08:55:18 test1 slapd[4919]: ber_get_next on fd 13 failed errno=11
(Resource temporarily unavailable)
Jul 30 08:55:18 test1 slapd[4919]: daemon: select: listen=7
active_threads=0 tvp=NULL
Jul 30 08:55:18 test1 slapd[4919]: daemon: select: listen=8
active_threads=0 tvp=NULL
Jul 30 08:55:18 test1 slapd[4919]: do_bind
Jul 30 08:55:18 test1 slapd[4919]: >>> dnPrettyNormal:
<cn=syncuser,dc=mydomain,dc=com>
Jul 30 08:55:18 test1 slapd[4919]: <<< dnPrettyNormal:
<cn=syncuser,dc=mydomain,dc=com>,
<cn=syncuser,dc=mydomain,dc=com>
Jul 30 08:55:18 test1 slapd[4919]: do_bind: version=3
dn="cn=syncuser,dc=mydomain,dc=com" method=128
Jul 30 08:55:18 test1 slapd[4919]: conn=0 op=0 BIND
dn="cn=syncuser,dc=mydomain,dc=com" method=128
Jul 30 08:55:18 test1 slapd[4919]: ==> bdb_bind: dn:
cn=syncuser,dc=mydomain,dc=com
Jul 30 08:55:18 test1 slapd[4919]:
bdb_dn2entry("cn=syncuser,dc=mydomain,dc=com")
Jul 30 08:55:18 test1 slapd[4919]: =>
bdb_dn2id("cn=syncuser,dc=mydomain,dc=com")
Jul 30 08:55:18 test1 slapd[4919]: <= bdb_dn2id: get failed:
DB_NOTFOUND: No matching key/data pair found (-30989)
Jul 30 08:55:18 test1 slapd[4919]: send_ldap_result: conn=0 op=0 p=3
Jul 30 08:55:18 test1 slapd[4919]: send_ldap_result: err=49 matched=""
text=""
Jul 30 08:55:18 test1 slapd[4919]: send_ldap_response: msgid=1 tag=97
err=49
Jul 30 08:55:18 test1 slapd[4919]: conn=0 op=0 RESULT tag=97 err=49
text=


Googling for do_syncrep1: ldap_sasl_bind_s failed (49) indicates that
this is likely to be an authentication issue with my syncuser.  I
double-checked the password, and verified that it's set as cleartext in
slapd.conf  I then tried to log on to a machine using the producer as
the authentication server, since there's nothing (that I can think of)
that makes this user in any way special.  It logs on... and about a
half second later is booted back out.  No logs on the client machine
indicate why.

Googling bdb_dn2id: get failed: DB_NOTFOUND: No matching key/data pair
found (-30989) led to many mentions of this almost certainly being a
permissions issue, but:

[root@test1 ~]# ls -l /var/lib/ldap/
total 69816
-rw-r--r-- 1 ldap ldap      2048 Jul 30 08:54 alock
-rw------- 1 ldap ldap     28672 Jul 29 15:45 cn.bdb
-rw------- 1 ldap ldap     24576 Jul 29 15:45 __db.001
-rw------- 1 ldap ldap  80019456 Jul 29 15:45 __db.002
-rw------- 1 ldap ldap 335552512 Jul 29 15:45 __db.003
-rw------- 1 ldap ldap   2359296 Jul 29 15:45 __db.004
-rw------- 1 ldap ldap    352256 Jul 29 15:45 __db.005
-rw------- 1 ldap ldap     24576 Jul 29 15:45 __db.006
-rw-r----- 1 ldap ldap       886 Jul 29 15:41 DB_CONFIG
-rw------- 1 ldap ldap     24576 Jul 29 15:45 dn2id.bdb
-rw------- 1 ldap ldap      8192 Jul 29 15:45 gidNumber.bdb
-rw------- 1 ldap ldap     20480 Jul 29 15:45 givenName.bdb
-rw------- 1 ldap ldap     98304 Jul 30 08:54 id2entry.bdb
-rw------- 1 ldap ldap  10485760 Jul 30 08:54 log.0000000001
-rw------- 1 ldap ldap      8192 Jul 29 15:45 loginShell.bdb
-rw------- 1 ldap ldap      8192 Jul 29 15:45 mail.bdb
-rw------- 1 ldap ldap     20480 Jul 29 15:45 memberUid.bdb
-rw------- 1 ldap ldap      8192 Jul 29 15:45 objectClass.bdb
-rw------- 1 ldap ldap      8192 Jul 29 15:45 ou.bdb
-rw------- 1 ldap ldap     20480 Jul 29 15:45 sn.bdb
-rw------- 1 ldap ldap     20480 Jul 29 15:45 uid.bdb
-rw------- 1 ldap ldap      8192 Jul 29 15:45 uidNumber.bdb

They look OK to me.

What can I do to further troubleshoot this issue?  I want to make 100%
sure that my underlying LDAP is working before I tackle the SSL part.

-- 
***********************************************************************
* John Oliver                             http://www.john-oliver.net/ *
*                                                                     *
***********************************************************************