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

Re: RHEL4 related OpenLDAP master/slave question

Jukka Hienola wrote: 
Dear all,

I have set up and run successfully OpenLDAP 2.2.13-4 server as a master and slave server with replication so far, until something happened about a week ago. My slave ldap server stopped completely to answer any read requests to it's ldap directory. E.g. any ldapsearch command just hangs returning noting more than some info about the server. E.g. simple command like 'ldapsearch -x -v -h localhost uid=someuser' just print out

  ldap_initialize( ldap://localhost )
  filter: uid=someuser
  requesting: ALL
  # extended LDIF
  #
  # LDAPv3
  # base <> with scope sub
  # filter: uid=someuser
  # requesting: ALL
  #


I would like to send some extra information about my problem...

If I execute the following command on my ldap slave server

ldapsearch -x -v -b "dc=mydomain,dc=somewhere" -s sub \
  -D "cn=replicator,ou=dsa,dc=mydomain,dc=somewhere" -W "(uid=someuser)"

I'll get the following output to log file (with log level -1 in slapd.conf):
-----
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on 1 descriptors
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: new connection on 17
Dec 14 09:09:34 slavesrv slapd[8398]: conn=7 fd=17 ACCEPT from IP=128.214.126.25:35468 (IP=0.0.0.0:389)
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: added 17r
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on:
Dec 14 09:09:34 slavesrv slapd[8398]:
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=6 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=7 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=8 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=9 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on 1 descriptors
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on:
Dec 14 09:09:34 slavesrv slapd[8398]: 17r
Dec 14 09:09:34 slavesrv slapd[8398]:
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: read activity on 17
Dec 14 09:09:34 slavesrv slapd[8398]: connection_get(17)
Dec 14 09:09:34 slavesrv slapd[8398]: connection_get(17): got connid=7
Dec 14 09:09:34 slavesrv slapd[8398]: connection_read(17): checking for input on id=7
Dec 14 09:09:34 slavesrv slapd[8398]: ber_get_next on fd 17 failed errno=11 (Resource temporarily unavailable)
Dec 14 09:09:34 slavesrv slapd[8398]: do_bind
Dec 14 09:09:34 slavesrv slapd[8398]: >>> dnPrettyNormal: <cn=replicator,ou=dsa,dc=mydomain,dc=somewhere>
Dec 14 09:09:34 slavesrv slapd[8398]: <<< dnPrettyNormal: <cn=replicator,ou=dsa,dc=mydomain,dc=somewhere>, <cn=replicator,ou=dsa,dc=mydomain,dc=somewhere>
Dec 14 09:09:34 slavesrv slapd[8398]: do_bind: version=3 dn="cn=replicator,ou=dsa,dc=mydomain,dc=somewhere" method=128
Dec 14 09:09:34 slavesrv slapd[8398]: conn=7 op=0 BIND dn="cn=replicator,ou=dsa,dc=mydomain,dc=somewhere" method=128
Dec 14 09:09:34 slavesrv slapd[8398]: ==> bdb_bind: dn: cn=replicator,ou=dsa,dc=mydomain,dc=somewhere
Dec 14 09:09:34 slavesrv slapd[8398]: conn=7 op=0 BIND dn="cn=replicator,ou=DSA,dc=mydomain,dc=somewhere" mech=SIMPLE ssf=0
Dec 14 09:09:34 slavesrv slapd[8398]: do_bind: v3 bind: "cn=replicator,ou=dsa,dc=mydomain,dc=somewhere" to "cn=replicator,ou=DSA,dc=mydomain,dc=somewhere"
Dec 14 09:09:34 slavesrv slapd[8398]: send_ldap_result: conn=7 op=0 p=3
Dec 14 09:09:34 slavesrv slapd[8398]: send_ldap_result: err=0 matched="" text=""
Dec 14 09:09:34 slavesrv slapd[8398]: send_ldap_response: msgid=1 tag=97 err=0
Dec 14 09:09:34 slavesrv slapd[8398]: conn=7 op=0 RESULT tag=97 err=0 text=
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=6 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=7 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=8 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: select: listen=9 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on 1 descriptors
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: activity on:
Dec 14 09:09:34 slavesrv slapd[8398]: 17r
Dec 14 09:09:34 slavesrv slapd[8398]:
Dec 14 09:09:34 slavesrv slapd[8398]: daemon: read activity on 17
Dec 14 09:09:34 slavesrv slapd[8398]: connection_get(17)
Dec 14 09:09:34 slavesrv slapd[8398]: connection_get(17): got connid=7
Dec 14 09:09:34 slavesrv slapd[8398]: connection_read(17): checking for input on id=7
Dec 14 09:09:34 slavesrvslapd[8398]: ber_get_next on fd 17 failed errno=11 (Resource temporarily unavailable)
Dec 14 09:09:34 slavesrvslapd[8398]: do_search
Dec 14 09:09:34 slavesrvslapd[8398]: >>> dnPrettyNormal: <dc=mydomain,dc=somewhere>
Dec 14 09:09:34 slavesrvslapd[8398]: <<< dnPrettyNormal: <dc=mydomain,dc=somewhere>, <dc=mydomain,dc=somewhere>
Dec 14 09:09:34 slavesrvslapd[8398]: SRCH "dc=mydomain,dc=somewhere" 2 0
Dec 14 09:09:34 slavesrvslapd[8398]: 0 0 0
Dec 14 09:09:34 slavesrvslapd[8398]: begin get_filter
Dec 14 09:09:34 slavesrvslapd[8398]: EQUALITY
Dec 14 09:09:34 slavesrvslapd[8398]: end get_filter 0
Dec 14 09:09:34 slavesrvslapd[8398]: filter: (uid=someuser)
Dec 14 09:09:34 slavesrvslapd[8398]: attrs:
Dec 14 09:09:34 slavesrvslapd[8398]:
Dec 14 09:09:34 slavesrvslapd[8398]: conn=7 op=1 SRCH base="dc=mydomain,dc=somewhere" scope=2 deref=0 filter="(uid=someuser)"
Dec 14 09:09:34 slavesrvslapd[8398]: => bdb_search
Dec 14 09:09:34 slavesrvslapd[8398]: bdb_dn2entry("dc=mydomain,dc=somewhere")
Dec 14 09:09:34 slavesrvslapd[8398]: daemon: select: listen=6 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrvslapd[8398]: daemon: select: listen=7 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrvslapd[8398]: daemon: select: listen=8 active_threads=0 tvp=NULL
Dec 14 09:09:34 slavesrvslapd[8398]: daemon: select: listen=9 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrvslapd[8398]: daemon: activity on 1 descriptors
Dec 14 09:09:39 slavesrvslapd[8398]: daemon: activity on:
Dec 14 09:09:39 slavesrv slapd[8398]: 17r
Dec 14 09:09:39 slavesrv slapd[8398]:
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: read activity on 17
Dec 14 09:09:39 slavesrv slapd[8398]: connection_get(17)
Dec 14 09:09:39 slavesrv slapd[8398]: connection_get(17): got connid=7
Dec 14 09:09:39 slavesrv slapd[8398]: connection_read(17): checking for input on id=7
Dec 14 09:09:39 slavesrv slapd[8398]: ber_get_next on fd 17 failed errno=0 (Success)
Dec 14 09:09:39 slavesrv slapd[8398]: connection_read(17): input error=-2 id=7, closing.
Dec 14 09:09:39 slavesrv slapd[8398]: connection_closing: readying conn=7 sd=17 for close
Dec 14 09:09:39 slavesrv slapd[8398]: connection_close: deferring conn=7 sd=17
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=6 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=7 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=8 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=9 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: activity on 1 descriptors
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=6 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=7 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=8 active_threads=0 tvp=NULL
Dec 14 09:09:39 slavesrv slapd[8398]: daemon: select: listen=9 active_threads=0 tvp=NULL
-----

However, if I execute the following command (with -h mastersrv) on my slave server

ldapsearch -x -v -b "dc=mydomain,dc=somewhere" -s sub -h mastersrv \
  -D "cn=replicator,ou=dsa,dc=mydomain,dc=somewhere" -W "(uid=someuser)"

I'll get the desired output.

In above log file, what could line "... connection_read(<>) input error=-2 id=<>, closing." mean?

Jukka
--
IT Services Administrator, Department of Physical Sciences,
University of Helsinki, firstname lastname at helsinki fi,
tel. +358 (0)9 191 50713, fax. +358 (0)9 191 50610