On Sun, Dec 04, 2016 at 11:03:25PM +0000, Howard Chu wrote:
> Brendan Kearney wrote:
> > On 12/04/2016 04:49 PM, Quanah Gibson-Mount wrote:
> > > Again, Mirror Mode is a concept, not a setting. The setting you refer to,
> > > is, as I previously noted, misnamed. Either your servers are configured to
> > > do multimaster replication, or they aren't.
>
> Mirrormode - the concept - is irrelevant here. All of the official docs show
> the mirrormode setting being used in N-Way multimaster.
>
> > yes, i seem to be in the trap about the mirror mode misnomer. though
> > ambiguous, your statements indicate that mirror mode the setting is required
> > for n-way multi master replication.
>
> That is what the Admin Guide already says.
> >
> > i agree most of my traffic is reads. i have 7 examples of connections with
> > deferred operations. they are all SRCH's (i.e. reads). I seem to misrember
> > the source of the deferred connections. bind-dyndb-ldap does not show in my
> > logs. sssd access is what 6 of 7 examples show. below is one sample.
>
> This is just due to sssd being very poorly written. It spews out a bunch of
> LDAP requests without waiting for replies. It then abandons N-1 of the
> requests as soon as it reads the first reply. And then it reissues the
> remaining requests, over and over. Instead it should just wait a little
> longer for all the replies, instead of abandoning and resubmitting the same
> requests and wasting redundant work.
This is not how sssd is supposed to work, judging by the searches and
the searches being for all the same modifyTimestamp values, it looks
like a bug in sssd.
If you can reproduce this on-demand, could you please correlate logs
from the [domain] section and the [sudo] section of sssd.conf (the
higher the debug_level, the better, but at least 8, please) with the
server-side logs?
btw the sssd-users mailing list might be a better place to debug sssd.
In general I agree with Howard that sssd is at fault here, but at the
same time I don't think this is expected activity. We've seen a report
like this in the past, but could never reproduce it or get better debug
logs, so maybe you could help us trace this bug down?
>
> > ReceivedAt FromHost SysLogTag Message
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 fd=29 ACCEPT from
> > IP=192.168.88.4:59233 (IP=192.168.88.1:389)
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=0 SRCH base=""
> > scope=0 deref=0 filter="(objectClass=*)"
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=0 SRCH attr=*
> > altServer namingContexts supportedControl supportedExtension supportedFeatures
> > supportedLDAPVersion supportedSASLMechanisms domainControllerFunctionality
> > defaultNamingContext lastUSN highestCommittedUSN
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=0 SEARCH RESULT
> > tag=101 err=0 nentries=1 text=
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=1 BIND dn=""
> > method=163
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=1 RESULT tag=97
> > err=14 text=SASL(0): successful result:
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=2 BIND dn=""
> > method=163
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=2 RESULT tag=97
> > err=14 text=SASL(0): successful result:
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=3 BIND dn=""
> > method=163
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=3 BIND
> > authcid="host/hypervisor.bpk2.com@BPK2.COM "
> > authzid="host/hypervisor.bpk2.com@BPK2.COM "
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=3 BIND
> > dn="cn=hypervisor,ou=computers,dc=bpk2,dc=com" mech=GSSAPI sasl_ssf=56 ssf=56
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=3 RESULT tag=97
> > err=0 text=
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=4 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=4 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=8 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=8 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=9 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=9 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=10 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=10 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=6 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=6 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=7 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=7 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=5 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=5 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=11 ABANDON msg=5
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=12 ABANDON msg=6
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=13 ABANDON msg=7
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=14 ABANDON msg=8
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=15 ABANDON msg=9
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=16 ABANDON msg=10
> > 12/04/16 04:00 PM server1 slapd[5033]: conn=2434 op=17 ABANDON msg=11
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=19 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=18 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=18 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=19 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=20 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=20 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=21 ABANDON msg=19
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=22 ABANDON msg=20
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=23 ABANDON msg=21
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=24 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=24 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=26 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=26 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=27 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=27 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=25 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=25 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=28 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:03 PM server1 slapd[5033]: conn=2434 op=28 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:03 PM server1 slapd[5033]: connection_input: conn=2434
> > deferring operation: too many executing
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=29 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=29 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=30 ABANDON msg=25
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=31 ABANDON msg=26
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=32 ABANDON msg=27
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=33 ABANDON msg=28
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=34 ABANDON msg=29
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=35 ABANDON msg=30
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=36 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=36 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:04 PM server1 slapd[5033]: conn=2434 op=37 ABANDON msg=37
> > 12/04/16 04:07 PM server1 slapd[5033]: conn=2434 op=38 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:07 PM server1 slapd[5033]: conn=2434 op=38 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:07 PM server1 slapd[5033]: conn=2434 op=39 ABANDON msg=39
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=40 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=41 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=41 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=40 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=42 SRCH
> > base="ou=SUDO Groups,ou=Roles,dc=bpk2,dc=com" scope=2 deref=0
> > filter="(&(objectClass=sudoRole)(modifyTimestamp>= 20150104230653Z)(!( modifyTimestamp= 20150104230653Z)))"
> >
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=42 SRCH
> > attr=objectClass cn sudoCommand sudoHost sudoUser sudoOption sudoRunAs
> > sudoRunAsUser sudoRunAsGroup sudoNotBefore sudoNotAfter sudoOrder modifyTimestamp
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=43 ABANDON msg=41
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=44 ABANDON msg=42
> > 12/04/16 04:12 PM server1 slapd[5033]: conn=2434 op=45 ABANDON msg=43
> > 12/04/16 04:15 PM server1 slapd[5033]: conn=2434 op=46 UNBIND
> > 12/04/16 04:15 PM server1 slapd[5033]: conn=2434 fd=29 closed
> >
> >
> >
>
>
> --
> -- Howard Chu
> CTO, Symas Corp. http://www.symas.com
> Director, Highland Sun http://highlandsun.com/hyc/
> Chief Architect, OpenLDAP http://www.openldap.org/project/
>