[SOLVED] Large number of slapd connections

[bango]

I recently upgraded to 5.0.6 and am having some issues with slapd messages filling up my log files (specifically /var/log/zimbra.log). Here's a snippit of the messages.

Jun  2 22:12:41 arioch slapd[23452]: conn=645 fd=14 ACCEPT from IP=192.168.1.4:55632 (IP=192.168.1.4:389) 
Jun  2 22:12:41 arioch slapd[23452]: conn=645 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 
Jun  2 22:12:41 arioch slapd[23452]: conn=645 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 
Jun  2 22:12:41 arioch slapd[23452]: conn=645 op=0 RESULT tag=97 err=0 text= 
Jun  2 22:12:41 arioch slapd[23452]: conn=645 op=1 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)" 
Jun  2 22:12:41 arioch slapd[23452]: conn=645 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Jun  2 22:12:43 arioch slapd[23452]: conn=645 fd=14 closed (connection lost) 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 fd=14 ACCEPT from IP=192.168.1.4:55634 (IP=192.168.1.4:389) 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 op=0 RESULT tag=97 err=0 text= 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 op=1 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)" 
Jun  2 22:12:45 arioch slapd[23452]: conn=646 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 fd=34 ACCEPT from IP=192.168.1.4:55635 (IP=192.168.1.4:389) 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 op=0 RESULT tag=97 err=0 text= 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 op=1 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)" 
Jun  2 22:12:45 arioch slapd[23452]: conn=647 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Jun  2 22:12:47 arioch slapd[23452]: conn=646 fd=14 closed (connection lost) 
Jun  2 22:12:47 arioch slapd[23452]: conn=647 fd=34 closed (connection lost) 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 fd=14 ACCEPT from IP=192.168.1.4:55637 (IP=192.168.1.4:389) 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 op=0 RESULT tag=97 err=0 text= 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 op=1 SRCH base="cn=servers,cn=zimbra" scope=2 deref=3 filter="(objectClass=zimbraServer)" 
Jun  2 22:12:50 arioch slapd[23452]: conn=648 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 fd=34 ACCEPT from IP=192.168.1.4:55638 (IP=192.168.1.4:389) 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" method=128 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 op=0 BIND dn="uid=zimbra,cn=admins,cn=zimbra" mech=SIMPLE ssf=0 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 op=0 RESULT tag=97 err=0 text= 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 op=1 SRCH base="cn=config,cn=zimbra" scope=0 deref=3 filter="(objectClass=*)" 
Jun  2 22:12:50 arioch slapd[23452]: conn=649 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text= 
Jun  2 22:12:51 arioch slapd[23452]: conn=648 fd=14 closed (connection lost) 
Jun  2 22:12:51 arioch slapd[23452]: conn=649 fd=34 closed (connection lost)

Has anyone experienced this before? From what I can tell, I can send and receive mail successfully, it's just a matter of figuring why I'm seeing so many of these messages. Any suggestions?

[mmorse]

Safe to ignore, to debug stuff we are increasingly in need of more information:
Bug 27699 - Update LDAP logging to stats+sync
Bug 27207 - Log all access to LDAP

We're currently trying to find a middle ground via: Bug 28274 - LDAP Logging is too high


Old default: 32768 (OR 0x8000 OR none) would just log critical stuff

New defaults: 16640 = stats + sync, this is set only if 32768 was still present (in-case you set another value on your own).
Master: 32768 none (critical only)
Replicas: 49152 = none + sync = 32768 + 16384 (no stats but syncrepl entries
are logged)

For instance to set that replica value it would be:
zmlocalconfig -e ldap_log_level=49152
OR
zmlocalconfig -e ldap_log_level="none sync"

You can define it several ways (single interger in decimal or hexadecimal, or keywords) and then you can combine them - for instance these are equivalent:
loglevel 129
loglevel 0x81
loglevel 128 1
loglevel 0x80 0x1
loglevel acl trace

hexadecimal <> decimal conversion tool

The keyword any can be used as a shortcut to enable logging at all levels (equivalent to -1).

The keyword none, or the equivalent integer representation (32768 or 0x800), causes those messages that are always logged regardless of the configured loglevel to be output (specified & critical stuff). In fact, if no loglevel (or a 0 level) is defined, no logging occurs, so at least the none level is required to have high priority messages logged.

In short, 32768 (OR 0x8000 OR none) = only messages that get logged whatever log level is set, thus you get critical stuff.

If you want it 5.0.5 style:
zmlocalconfig -e ldap_log_level=32768
zmcontrol stop/start

To set back to 5.0.6 style:
zmlocalconfig -e ldap_log_level=16640
zmcontrol stop/start

[mmorse]

The gist: Your zimbra log isn't showing me a 'large number of slapd connections' it's just more verbose.

If you want LDAP logging as it was in 5.0.5 & prior:

su - zimbra
zmlocalconfig -e ldap_log_level=32768
zmcontrol stop/start

[bango]

mmorse,

Thanks for the quick response. This resolved the issue. What I didn't realize is that the LDAP logging levels changed between 5.0.5 and 5.0.6. Prior to seeing your suggestion, I actually started tinkering with the ldap_log_level parameter and turned it off.

It's good to hear that the behavior I was seeing is expected given the changes to ldap logging between versions. And double thanks for all the additional information you provided on ldap codes, keywords, etc.