Forums

Resolved
0 votes
Hi,

I noticing lately that the log files of openldap in /var/messages/openldap.log are very large (>100mb / week)

It looks like Kopano is having some issue, but i can not indentify the exact problem.
Everything works just fine, but i don't think this is normal


May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (clearMailDistributionList) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: conn=3562 op=5 SEARCH RESULT tag=101 err=0 nentries=0 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3566 fd=61 ACCEPT from IP=127.0.0.1:56702 (IP=127.0.0.1:389)
May 2 14:02:30 pdebrabander slapd[5095]: conn=3566 op=0 SRCH base="ou=Users,ou=Accounts,dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(|(clearMailAliases=jordy)(mail=jordy@*))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3566 op=0 SRCH attr=mail
May 2 14:02:30 pdebrabander slapd[5095]: conn=3566 op=0 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3564 op=2 SRCH base="ou=Users,ou=Accounts,dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(|(clearMailAliases=jordy)(mail=jordy@*))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3564 op=2 SRCH attr=mail
May 2 14:02:30 pdebrabander slapd[5095]: conn=3564 op=2 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3562 op=6 SRCH base="ou=Groups,ou=Accounts,dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(objectClass=clearMailGroupAccount)(clearMailDistributionList=1)(cn=pdebrabander.nl))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3562 op=6 SRCH attr=mail member
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (clearMailDistributionList) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: conn=3562 op=6 SEARCH RESULT tag=101 err=0 nentries=0 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=7 SRCH base="ou=Users,ou=Accounts,dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=jordy))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=7 SRCH attr=loginShell cn gidNumber uidNumber objectClass homeDirectory gecos uid
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=7 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=8 SRCH base="ou=Computers,ou=Accounts,dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(objectClass=posixAccount)(uid=jordy))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=8 SRCH attr=loginShell cn gidNumber uidNumber objectClass homeDirectory gecos uid
May 2 14:02:30 pdebrabander slapd[5095]: conn=3559 op=8 SEARCH RESULT tag=101 err=0 nentries=0 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3551 op=4 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(|(&(kopanoAccount=1)(|(objectClass=kopano-user)(objectClass=kopano-contact)))(&(kopanoAccount=1)(objectClass=kopano-contact))(|(&(objectClass=clearMailGroupAccount)(clearMailDistributionList=1))(objectClass=kopano-dynamicgroup))(|(&(objectClass=kopano-addresslist))))(|(uid=jordy@pdebrabander.nl)(cn=jordy@pdebrabander.nl)(mail=jordy@pdebrabander.nl)(clearMailAliases=jordy@pdebrabander.nl)(cn=jordy@pdebrabander.nl)(ou=jordy@pdebrabander.nl)(cn=jordy@pdebrabander.nl)(cn=jordy@pdebrabander.nl)))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3551 op=4 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (clearMailDistributionList) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (ou) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: conn=3551 op=4 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3540 op=6 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)(objectClass=kopano-contact)))(|(uid=jordy)))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3540 op=6 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: conn=3540 op=6 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3528 op=14 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)(objectClass=kopano-contact)))(|(uid=jordy)))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3528 op=14 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:30 pdebrabander slapd[5095]: conn=3528 op=14 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:30 pdebrabander slapd[5095]: conn=3551 op=5 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)(objectClass=kopano-contact)))(|(uid=jordy)))"
May 2 14:02:30 pdebrabander slapd[5095]: conn=3551 op=5 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:30 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed




May 2 14:02:33 pdebrabander slapd[5095]: conn=3528 op=23 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:33 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:33 pdebrabander slapd[5095]: conn=3528 op=23 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:33 pdebrabander slapd[5095]: conn=3528 op=24 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)))(uidNumber=2002))"
May 2 14:02:33 pdebrabander slapd[5095]: conn=3528 op=24 SRCH attr=dn
May 2 14:02:33 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:33 pdebrabander slapd[5095]: conn=3528 op=24 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 fd=62 ACCEPT from IP=127.0.0.1:56788 (IP=127.0.0.1:389)
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 op=0 BIND dn="cn=Jordy de Brabander,ou=Users,ou=Accounts,dc=pdebrabander,dc=nl" method=128
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 op=0 BIND dn="cn=Jordy de Brabander,ou=Users,ou=Accounts,dc=pdebrabander,dc=nl" mech=SIMPLE ssf=0
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 op=0 RESULT tag=97 err=0 text=
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 op=1 UNBIND
May 2 14:02:33 pdebrabander slapd[5095]: conn=3586 fd=62 closed
May 2 14:02:33 pdebrabander slapd[5095]: conn=3540 op=9 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)))(|(uid=jordy)))"
May 2 14:02:33 pdebrabander slapd[5095]: conn=3540 op=9 SRCH attr=objectClass kopanoResourceType kopanoSecurityGroup uidNumber cn ou cn cn modifyTimestamp
May 2 14:02:33 pdebrabander slapd[5095]: <= bdb_equality_candidates: (kopanoAccount) not indexed
May 2 14:02:33 pdebrabander slapd[5095]: conn=3540 op=9 SEARCH RESULT tag=101 err=0 nentries=1 text=
May 2 14:02:33 pdebrabander slapd[5095]: conn=3540 op=10 SRCH base="dc=pdebrabander,dc=nl" scope=2 deref=0 filter="(&(&(kopanoAccount=1)(|(objectClass=kopano-user)))(uidNumber=2002))"
Thursday, May 02 2019, 12:10 PM
Share this post:
Responses (4)
  • Accepted Answer

    Thursday, May 02 2019, 02:34 PM - #Permalink
    Resolved
    0 votes
    Unfortunately a developer came across an article recommending a particular log level and changed it around when 7.5 was released. It also looks like openldap has its own funny rotation scheme so you get left with log files of zero size. I reverted mine by setting "loglevel 0" in /etc/openldap/slapd.conf. I am campaigning to have the value reverted for everyone so the change may happen!
    The reply is currently minimized Show
  • Accepted Answer

    Thursday, May 02 2019, 08:23 PM - #Permalink
    Resolved
    0 votes
    My loglevel is set for 256 in /etc/openldap/slapd.conf. My log size has yet to be over 10M (knock on wood, since I just updated ClearOS Business to 7.6.0).

    Related to debug levels...this from openldap.org

    Table 6.1: Debugging Levels
    Level Keyword Description
    -1 any enable all debugging
    0 no debugging
    1 (0x1 trace) trace function calls
    2 (0x2 packets) debug packet handling
    4 (0x4 args) heavy trace debugging
    8 (0x8 conns) connection management
    16 (0x10 BER) print out packets sent and received
    32 (0x20 filter) search filter processing
    64 (0x40 config) configuration processing
    128 (0x80 ACL) access control list processing
    256 (0x100 stats) stats log connections/operations/results
    512 (0x200 stats2) stats log entries sent
    1024 (0x400 shell) print communication with shell backends
    2048 (0x800 parse) print entry parsing debugging
    16384 (0x4000 sync) syncrepl consumer processing
    32768 (0x8000 none) only messages that get logged whatever log level is set

    What's your loglevel set to?

    Perhaps your log size is so great because you use Kopano a lot and each time you log in, openldap has to query its entire database because some associated kopano attributes aren't indexed in openldap. Indexed attributes make the search process faster and I'm supposing logs smaller in size. Maybe submit this as an issue or task to the Clear team? In the mean time, you could do what Nick suggested and change the loglevel value to minimize the file size.
    The reply is currently minimized Show
  • Accepted Answer

    Friday, May 03 2019, 01:40 PM - #Permalink
    Resolved
    0 votes
    Dirk Albring wrote:

    My loglevel is set for 256 in /etc/openldap/slapd.conf. My log size has yet to be over 10M (knock on wood, since I just updated ClearOS Business to 7.6.0).

    Related to debug levels...this from openldap.org

    Table 6.1: Debugging Levels
    Level Keyword Description
    -1 any enable all debugging
    0 no debugging
    1 (0x1 trace) trace function calls
    2 (0x2 packets) debug packet handling
    4 (0x4 args) heavy trace debugging
    8 (0x8 conns) connection management
    16 (0x10 BER) print out packets sent and received
    32 (0x20 filter) search filter processing
    64 (0x40 config) configuration processing
    128 (0x80 ACL) access control list processing
    256 (0x100 stats) stats log connections/operations/results
    512 (0x200 stats2) stats log entries sent
    1024 (0x400 shell) print communication with shell backends
    2048 (0x800 parse) print entry parsing debugging
    16384 (0x4000 sync) syncrepl consumer processing
    32768 (0x8000 none) only messages that get logged whatever log level is set

    What's your loglevel set to?

    Perhaps your log size is so great because you use Kopano a lot and each time you log in, openldap has to query its entire database because some associated kopano attributes aren't indexed in openldap. Indexed attributes make the search process faster and I'm supposing logs smaller in size. Maybe submit this as an issue or task to the Clear team? In the mean time, you could do what Nick suggested and change the loglevel value to minimize the file size.


    Loglevel was set to 256.
    There are only 4 users, so this cannot be give a huge activity in the logs

    I've now set the loglevel to "0" , let's see what happens
    The reply is currently minimized Show
  • Accepted Answer

    Monday, May 06 2019, 10:34 AM - #Permalink
    Resolved
    0 votes
    I guess where I was going with my comment was, I don’t use Kopano much at all, so I’m thinking with one user my openldap log wouldn’t be too big and overly populated with non-indexed Kopano dB attributes. However, maybe even with 4 users, if those 4 users use Kopano a lot, then perhaps the openldap log would be large in size with non-indexed messages.
    The reply is currently minimized Show
Your Reply