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

Re: password policy module memory leaks / excessive replication?

To: Quanah Gibson-Mount <quanah@zimbra.com>
Subject: Re: password policy module memory leaks / excessive replication?
From: "Paul B. Henson" <henson@acm.org>
Date: Wed, 7 May 2014 14:57:07 -0700
Cc: openldap-technical@openldap.org
Content-disposition: inline
Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=sender:date:from:to:cc:subject:message-id:references:mime-version :content-type:content-disposition:in-reply-to:user-agent; bh=JDDbb3v6RRgu5mpEPi0uMuioO9V7bw2PqZvNEPwnOjk=; b=t85mooXtSPTRfNq8Ricy+CckGABTU8OethIfbrNxSwK3UanbKivlAyCPBgRrF6d94T fAqVC7zqVXhLV5k5GuSZPIuYjflnS4y7RzLmfPtRFErvRxqt4oL/9Ei8k6IteL5aPvG/ 7zKJ8jTUoIOM+fo5LUNEwOQ2WgGeCCUIChk+0UYtJILhDZgGNdNu44aNwCKW2iKu4L9P CoIG+gpykpruNwDEstCeZGBRsiuN20l54JyyPybXRXFVUvG3tgc3YeFyxL7V929UMYrt jphxKft+F7Sf6LXraaJcdTSNQqA/UC5/NivQ3m4j1W2YoMVTi4oSvabtntfoAB6Yf9ju 7zGQ==
In-reply-to: <F1AF1A835B58A22F8E43339A@[192.168.1.15]>
References: <184d01cf666b$28eabd00$7ac03700$@acm.org> <7AC81676D5A51377F128A3D4@[192.168.1.15]> <20140506203922.GJ1367@bender.unx.csupomona.edu> <480171C1D8DAF04160585CC5@[192.168.1.15]> <F1AF1A835B58A22F8E43339A@[192.168.1.15]>
User-agent: Mutt/1.5.23 (2014-03-12)

On Wed, May 07, 2014 at 09:42:12AM -0700, Quanah Gibson-Mount wrote:

> One other thing -- Did any of your servers go into refresh mode prior to 
> this loop starting?

Yes, it started logging:

May  5 19:00:38 filmore-dev slapd[7665]: do_syncrep2: rid=001
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:01:48 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync, switching to REFRESH

It continued logging the lost sync messages almost continuously until:

May  5 19:06:16 filmore-dev slapd[7665]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
May  5 19:06:19 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:06:26 filmore-dev slapd[7665]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
May  5 19:06:32 filmore-dev slapd[7665]: do_syncrep2: rid=002
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 20:10:32 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506031032.000017Z,cn=accesslog), switching
to REFRESH
May  5 20:10:32 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 21:30:34 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506043034.000008Z,cn=accesslog), switching
to REFRESH
May  5 21:31:26 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 22:10:36 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506051035.000019Z,cn=accesslog), switching
to REFRESH
May  5 22:10:36 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 22:45:33 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506054533.000016Z,cn=accesslog), switching
to REFRESH
May  5 22:45:33 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 23:10:35 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506061035.000008Z,cn=accesslog), switching
to REFRESH
May  5 23:11:27 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  6 02:15:05 filmore-dev slapd[7665]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506075534.000068Z,cn=accesslog), switching
to REFRESH
May  6 02:28:40 filmore-dev slapd[7665]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE


The others had similar logs:


May  5 19:00:40 fosse-dev slapd[7791]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
May  5 19:00:40 fosse-dev slapd[7791]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
[...]
May  5 19:10:33 fosse-dev slapd[7791]: do_syncrep2: rid=001 delta-sync
lost sync, switching to REFRESH
May  5 19:10:36 fosse-dev slapd[7791]: do_syncrep2: rid=001
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:20:33 fosse-dev slapd[7791]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506022033.000008Z,cn=accesslog), switching
to REFRESH
May  5 19:20:33 fosse-dev slapd[7791]: do_syncrep2: rid=001 delta-sync
lost sync on (reqStart=20140506022033.000009Z,cn=accesslog), switching
to REFRESH
May  5 19:20:33 fosse-dev slapd[7791]: do_syncrep2: rid=002 delta-sync
lost sync on (reqStart=20140506022033.000009Z,cn=accesslog), switching
to REFRESH
May  5 19:20:33 fosse-dev slapd[7791]: do_syncrep2: rid=001
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:20:33 fosse-dev slapd[7791]: do_syncrep2: rid=002
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:21:26 fosse-dev slapd[7791]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 21:30:34 fosse-dev slapd[7791]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506043034.000008Z,cn=accesslog), switching
to REFRESH


May  5 19:02:17 shelley-dev slapd[8178]: do_syncrep2: rid=003 delta-sync
lost sync, switching to REFRESH
May  5 19:02:17 shelley-dev slapd[8178]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
May  5 19:02:17 shelley-dev slapd[8178]: do_syncrep2: rid=001
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:02:21 shelley-dev slapd[8178]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
[...]
May  5 19:06:19 shelley-dev slapd[8178]: do_syncrep2: rid=002 delta-sync
lost sync, switching to REFRESH
May  5 19:06:19 shelley-dev slapd[8178]: do_syncrep2: rid=002
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 19:06:19 shelley-dev slapd[8178]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 20:10:32 shelley-dev slapd[8178]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506031032.000017Z,cn=accesslog), switching
to REFRESH
May  5 20:10:32 shelley-dev slapd[8178]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 21:30:34 shelley-dev slapd[8178]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506043034.000008Z,cn=accesslog), switching
to REFRESH
May  5 21:30:34 shelley-dev slapd[8178]: do_syncrep2: rid=003
LDAP_RES_INTERMEDIATE - REFRESH_DELETE
May  5 22:45:33 shelley-dev slapd[8178]: do_syncrep2: rid=003 delta-sync
lost sync on (reqStart=20140506054533.000016Z,cn=accesslog), switching
to REFRESH


I don't know if it's related, but right before the loop it was
replicating pwdFailureTime time changes around:

dn: reqStart=20140506064532.000030Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20140506064532.000030Z
reqEnd: 20140506064532.000033Z
reqType: modify
reqSession: 3
reqAuthzID: cn=ldaproot,dc=csupomona,dc=edu
reqDN: cn=slapd-monitor,ou=user,ou=service,dc=csupomona,dc=edu
reqResult: 0
reqMod: pwdFailureTime:+ 20140506064532Z
reqMod: entryCSN:= 20140506064532.612089Z#000000#003#000000
reqMod: modifiersName:= cn=ldaproot,dc=csupomona,dc=edu
reqMod: modifyTimestamp:= 20140506064532Z
reqEntryUUID: c16729b0-ce1e-4f9d-9123-e0b8f115133c
entryUUID: a1e99b9b-64b8-4e79-9451-48cac10ff333
creatorsName: cn=accesslog
createTimestamp: 20140506064532Z
entryCSN: 20140506064532.612089Z#000000#003#000000
modifiersName: cn=accesslog
modifyTimestamp: 20140506064532Z

dn: reqStart=20140506064532.000034Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20140506064532.000034Z
reqEnd: 20140506064532.000035Z
reqType: modify
reqSession: 5048
reqAuthzID: cn=ldaproot,dc=csupomona,dc=edu
reqDN: cn=slapd-monitor,ou=user,ou=service,dc=csupomona,dc=edu
reqResult: 0
reqMod: pwdFailureTime:-
reqMod: entryCSN:= 20140506064532.680931Z#000000#002#000000
reqMod: modifiersName:= cn=ldaproot,dc=csupomona,dc=edu
reqMod: modifyTimestamp:= 20140506064532Z
reqEntryUUID: c16729b0-ce1e-4f9d-9123-e0b8f115133c
entryUUID: 557c4163-5170-4dc1-84c4-0159797d5538
creatorsName: cn=accesslog
createTimestamp: 20140506064532Z
entryCSN: 20140506064532.680931Z#000000#002#000000
modifiersName: cn=accesslog
modifyTimestamp: 20140506064532Z

dn: reqStart=20140506064532.000040Z,cn=accesslog
objectClass: auditModify
structuralObjectClass: auditModify
reqStart: 20140506064532.000040Z
reqEnd: 20140506064532.000043Z
reqType: modify
reqSession: 3
reqAuthzID: cn=ldaproot,dc=csupomona,dc=edu
reqDN: cn=slapd-monitor,ou=user,ou=service,dc=csupomona,dc=edu
reqResult: 0
reqMod: pwdFailureTime:+ 20140506064532Z
reqMod: entryCSN:= 20140506064532.861668Z#000000#003#000000
reqMod: modifiersName:= cn=ldaproot,dc=csupomona,dc=edu
reqMod: modifyTimestamp:= 20140506064532Z
reqEntryUUID: c16729b0-ce1e-4f9d-9123-e0b8f115133c
entryUUID: c4ba3c02-b67a-4522-8767-8da1fa084916
creatorsName: cn=accesslog
createTimestamp: 20140506064532Z
entryCSN: 20140506064532.861668Z#000000#003#000000
modifiersName: cn=accesslog
modifyTimestamp: 20140506064532Z

Follow-Ups:
- Re: password policy module memory leaks / excessive replication?
  - From: Quanah Gibson-Mount <quanah@zimbra.com>

References:
- password policy module memory leaks / excessive replication?
  - From: "Paul B. Henson" <henson@acm.org>
- Re: password policy module memory leaks / excessive replication?
  - From: Quanah Gibson-Mount <quanah@zimbra.com>
- Re: password policy module memory leaks / excessive replication?
  - From: "Paul B. Henson" <henson@acm.org>
- Re: password policy module memory leaks / excessive replication?
  - From: Quanah Gibson-Mount <quanah@zimbra.com>
- Re: password policy module memory leaks / excessive replication?
  - From: Quanah Gibson-Mount <quanah@zimbra.com>

Prev by Date: Re: Phantom certificates?
Next by Date: Re: password policy module memory leaks / excessive replication?
Index(es):
- Chronological
- Thread