[Date Prev][Date Next] [Chronological] [Thread] [Top]
proxy hangs irreversible if the first mirror in the uri list is down

To: openldap-software@openldap.org
Subject: proxy hangs irreversible if the first mirror in the uri list is down
From: Christian Fischer <Christian.Fischer@fischundfischer.com>
Date: Thu, 4 Jun 2009 15:51:07 +0200
Content-disposition: inline
User-agent: KMail/1.9.9
Hi all,

I'm running openldap-2.4.16 on gentoo amd64.

I've configured two server in mirror mode and one running as proxy.

Everything runs fine if both mirrors are online or offline.

The proxy hangs if the first mirror in the uri list is offline.
In this case the proxy can't be shutdowned, i must kill him with signal 9.
Starting mirror one has no effect, the proxy hanges on connection 2, no 
reconnect, no timeout.


What do you suggest to figure out what's going wrong?
Attached the proxy config and some log snippets.

Best regards
Christian


### config proxy ###

#
# See slapd.conf(5) for details on configuration options.
# This file should NOT be world readable.
#
include /etc/openldap/schema/core.schema
include /etc/openldap/schema/cosine.schema
include /etc/openldap/schema/inetorgperson.schema
include /etc/openldap/schema/rfc2307bis.schema
include /etc/openldap/schema/samba.schema
include /etc/openldap/schema/misc.schema
include /etc/openldap/schema/openssh-lpk.schema
include /etc/openldap/schema/radius.schema
include /etc/openldap/schema/egr.schema
include /etc/openldap/schema/mozillaabpersonalpha.schema
include /etc/openldap/schema/dhcp.schema

pidfile         /var/run/openldap/slapd.pid
argsfile        /var/run/openldap/slapd.args

# Load dynamic backend modules:
# modulepath    /usr/lib64/openldap/openldap
# moduleload    back_sock.so
# moduleload    back_shell.so
# moduleload    back_relay.so
# moduleload    back_perl.so
# moduleload    back_passwd.so
# moduleload    back_null.so
# moduleload    back_monitor.so
#moduleload     back_meta.so
moduleload      back_ldap.so
# moduleload    back_dnssrv.so

loglevel        -1
database        ldap
suffix          "dc=easterngraphics,dc=com"
uri  "ldap://isc01.easterngraphics.com ldap://isc02.easterngraphics.com";
tls             start tls_reqcert=never

acl-bind        bindmethod=simple
                binddn="cn=manager,dc=easterngraphics,dc=com"
                credentials=seret

### end config ###


### log snippet with both mirrors offline ###

Jun  4 15:43:50 gatekeeper slapd[2447]: backend_startup_one: 
starting "dc=easterngraphics,dc=com"
Jun  4 15:43:50 gatekeeper slapd[2447]: ldap_back_db_open: 
URI=ldap://isc01.easterngraphics.com ldap://isc02.easterngraphics.com
Jun  4 15:43:50 gatekeeper slapd[2447]: slapd starting
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: added 4r listener=(nil)
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: added 7r listener=0x7da180
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:43:50 gatekeeper slapd[2447]:
Jun  4 15:43:50 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL


### start request ###

Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: slap_listener_activate(7):
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 busy
Jun  4 15:44:26 gatekeeper slapd[2447]: >>> 
slap_listener(ldap://192.168.9.254)
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: listen=7, new connection on 9
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:  9r
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: read active on 9
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: added 9r (active) 
listener=(nil)
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 fd=9 ACCEPT from 
IP=192.168.9.225:48622 (IP=192.168.9.254:389)
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_get(9)
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_get(9): got connid=0
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_read(9): checking for input 
on id=0
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 op=0 do_bind
Jun  4 15:44:26 gatekeeper slapd[2447]: >>> dnPrettyNormal: 
<cn=manager,dc=easterngraphics,dc=com>
Jun  4 15:44:26 gatekeeper slapd[2447]: <<< dnPrettyNormal: 
<cn=manager,dc=easterngraphics,dc=com>, 
<cn=manager,dc=easterngraphics,dc=com>
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 op=0 BIND 
dn="cn=manager,dc=easterngraphics,dc=com" method=128
Jun  4 15:44:26 gatekeeper slapd[2447]: do_bind: version=3 
dn="cn=manager,dc=easterngraphics,dc=com" method=128
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:44:26 gatekeeper slapd[2447]: send_ldap_result: conn=0 op=0 p=3
Jun  4 15:44:26 gatekeeper slapd[2447]: send_ldap_result: err=52 matched="" 
text="Start TLS failed"
Jun  4 15:44:26 gatekeeper slapd[2447]: send_ldap_response: msgid=1 tag=97 
err=52
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 op=0 RESULT tag=97 err=52 
text=Start TLS failed
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:  9r
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: read active on 9
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_get(9)
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_get(9): got connid=0
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_read(9): checking for input 
on id=0
Jun  4 15:44:26 gatekeeper slapd[2447]: ber_get_next on fd 9 failed errno=0 
(Success)
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_read(9): input error=-2 
id=0, closing.
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_closing: readying conn=0 
sd=9 for close
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:44:26 gatekeeper slapd[2447]:
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_close: deferring conn=0 
sd=9
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 op=1 do_unbind
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 op=1 UNBIND
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_resched: attempting closing 
conn=0 sd=9
Jun  4 15:44:26 gatekeeper slapd[2447]: connection_close: conn=0 sd=9
Jun  4 15:44:26 gatekeeper slapd[2447]: =>ldap_back_conn_destroy: fetching 
conn 0
Jun  4 15:44:26 gatekeeper slapd[2447]: daemon: removing 9
Jun  4 15:44:26 gatekeeper slapd[2447]: conn=0 fd=9 closed



### start mirror two, let mirror one offline, new request ###


Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:45:37 gatekeeper slapd[2447]:
Jun  4 15:45:37 gatekeeper slapd[2447]: slap_listener_activate(7):
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: epoll: listen=7 busy
Jun  4 15:45:37 gatekeeper slapd[2447]: >>> 
slap_listener(ldap://192.168.9.254)
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: listen=7, new connection on 9
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: added 9r (active) 
listener=(nil)
Jun  4 15:45:37 gatekeeper slapd[2447]: conn=1 fd=9 ACCEPT from 
IP=192.168.9.225:53900 (IP=192.168.9.254:389)
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on 2 descriptors
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:45:37 gatekeeper slapd[2447]:  9r
Jun  4 15:45:37 gatekeeper slapd[2447]:
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: read active on 9
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL
Jun  4 15:45:37 gatekeeper slapd[2447]: connection_get(9)
Jun  4 15:45:37 gatekeeper slapd[2447]: connection_get(9): got connid=1
Jun  4 15:45:37 gatekeeper slapd[2447]: connection_read(9): checking for input 
on id=1
Jun  4 15:45:37 gatekeeper slapd[2447]: conn=1 op=0 do_bind
Jun  4 15:45:37 gatekeeper slapd[2447]: >>> dnPrettyNormal: 
<cn=manager,dc=easterngraphics,dc=com>
Jun  4 15:45:37 gatekeeper slapd[2447]: <<< dnPrettyNormal: 
<cn=manager,dc=easterngraphics,dc=com>, 
<cn=manager,dc=easterngraphics,dc=com>
Jun  4 15:45:37 gatekeeper slapd[2447]: conn=1 op=0 BIND 
dn="cn=manager,dc=easterngraphics,dc=com" method=128
Jun  4 15:45:37 gatekeeper slapd[2447]: do_bind: version=3 
dn="cn=manager,dc=easterngraphics,dc=com" method=128
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on 1 descriptor
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: activity on:
Jun  4 15:45:37 gatekeeper slapd[2447]:
Jun  4 15:45:37 gatekeeper slapd[2447]: daemon: epoll: listen=7 
active_threads=0 tvp=NULL


### mirror hangs now, try to shutdown ###

Jun  4 15:47:02 gatekeeper slapd[2447]: daemon: shutdown requested and 
initiated.
Jun  4 15:47:02 gatekeeper slapd[2447]: daemon: closing 7
Jun  4 15:47:02 gatekeeper slapd[2447]: connection_closing: readying conn=1 
sd=9 for close
Jun  4 15:47:02 gatekeeper slapd[2447]: connection_close: deferring conn=1 
sd=9
Jun  4 15:47:02 gatekeeper slapd[2447]: slapd shutdown: waiting for 1 
operations/tasks to finish


-- 
"Without music to decorate it, time is just a bunch of boring production
 deadlines or dates by which bills must be paid."
        --- Frank Vincent Zappa
Follow-Ups:
- Re: proxy hangs irreversible if the first mirror in the uri list is down
  - From: masarati@aero.polimi.it
Prev by Date: Re: Changing password with replicat and referal do nothing
Next by Date: Re: proxy hangs irreversible if the first mirror in the uri list is down
Index(es):
- Chronological
- Thread