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

Re: password policy module memory leaks / excessive replication?

To: "Paul B. Henson" <henson@acm.org>
Subject: Re: password policy module memory leaks / excessive replication?
From: Quanah Gibson-Mount <quanah@zimbra.com>
Date: Wed, 7 May 2014 19:57:56 -0500 (CDT)
Cc: "openldap-technical@openldap.org" <openldap-technical@openldap.org>
Dkim-filter: OpenDKIM Filter v2.9.1 edge01.zimbra.com EDC9D4426C
Dkim-signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=zimbra.com; s=C2AA288C-EE47-11E2-9BB0-E820BDD9BDBF; t=1399510677; bh=EE4OZ0LJpJ8J3DmaakAPnSuLtCOQKkudcrP4MXbdiXY=; h=Content-Type:Content-Transfer-Encoding:MIME-Version:Message-Id: From:Subject:Date:To; b=ZLkKx7BFsNIMuAv7C5OGYXxhjrXjZUkzFw1crS5ycExRYP4L/yqDsWmSG91Sl63pQ OZ4T2iSLiV7CYN2HgJJxQ3BlNRGE97zODBGnAJgWHi51sT1Kc4pLzhKXaGez0uzj2F Opg42CJ+QFF9g60J1Z6H4BjvXgfoVa4LU0y8UR6g=
In-reply-to: <20140507215707.GK1367@bender.unx.csupomona.edu>
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]> <20140507215707.GK1367@bender.unx.csupomona.edu>
Thread-index: a0JLAyBTu38g0Mqn5WfiRb+hHiKyQg==
Thread-topic: password policy module memory leaks / excessive replication?

I've filed an ITS on the issue and will see if I can replicate it in our lab. This looks exactly like what I am seeing as well. Howard may be able to provide some gdb actions he would like to see as well.

--Quanah

> On May 7, 2014, at 2:57 PM, "Paul B. Henson" <henson@acm.org> wrote:
> 
>> 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: "Paul B. Henson" <henson@acm.org>

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>
- Re: password policy module memory leaks / excessive replication?
  - From: "Paul B. Henson" <henson@acm.org>

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