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

send_ldap_response: ber write failed



Hi,

I have those errors BER write errors that have crept up recently on 2 slapd
providers in a mirror replication setup and I can't seem to find the cause of
them. I must have made a change to the config but pea brain of me can't seem to
find the root of it. They are now occurring a few times a day.

I have turned on BER, conns, stats, and sync debugging but it's still unclear
to me what is going on. Can anyone shed some light?

IP=172.16.10.247 is a HAproxy server with the 2 mirrors as backends.
There is also a Munin host that polls the providers every 5m or so to gather stats.

Thanks and Happy Holiday!
jf

Here a anonymized excerpt of the logs of one server showing the error message:

Dec 26 03:20:45 ldap-server slapd[4306]: daemon: listen=8, new connection on 18
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: added 18r (active) listener=(nil)
Dec 26 03:20:45 ldap-server slapd[4306]: conn=2799347 fd=18 ACCEPT from IP=172.16.10.247:33746 (IP=0.0.0.0:389)
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 2 descriptors
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]:  18r
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: read active on 18
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: conn=2799347 op=0 BIND dn="" method=128
Dec 26 03:20:45 ldap-server slapd[4306]: conn=2799347 op=0 RESULT tag=97 err=0 text=
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]:  18r
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: read active on 18
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: connection_read(18): input error=-2 id=2799347, closing.
Dec 26 03:20:45 ldap-server slapd[4306]: connection_closing: readying conn=2799347 sd=18 for close
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: removing 18
Dec 26 03:20:45 ldap-server slapd[4306]: conn=2799347 fd=18 closed (connection lost)
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:45 ldap-server slapd[4306]: 
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:45 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: activity on 1 descriptor
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: activity on:
Dec 26 03:20:46 ldap-server slapd[4306]:  15r
Dec 26 03:20:46 ldap-server slapd[4306]: 
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: read active on 15
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: epoll: listen=8 active_threads=0 tvp=zero
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: epoll: listen=9 active_threads=0 tvp=zero
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: epoll: listen=10 active_threads=0 tvp=zero
Dec 26 03:20:46 ldap-server slapd[4306]: conn=2799050 op=3 SRCH base="dc=example,dc=com" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=root))"
Dec 26 03:20:46 ldap-server slapd[4306]: ber_flush2 failed errno=32 reason="Broken pipe"
Dec 26 03:20:46 ldap-server slapd[4306]: connection_closing: readying conn=2799050 sd=15 for close
Dec 26 03:20:46 ldap-server slapd[4306]: send_ldap_response: ber write failed
Dec 26 03:20:46 ldap-server slapd[4306]: conn=2799050 op=3 SEARCH RESULT tag=101 err=0 nentries=0 text=
Dec 26 03:20:46 ldap-server slapd[4306]: connection_resched: attempting closing conn=2799050 sd=15
Dec 26 03:20:46 ldap-server slapd[4306]: daemon: removing 15
Dec 26 03:20:46 ldap-server slapd[4306]: conn=2799050 fd=15 closed (connection lost on write)