will do so later today.  seems pretty consistent, so I should have logs for the sssd mailing list

On Dec 5, 2016 11:12 AM, "Jakub Hrozek" <jakub.hrozek@posteo.se> wrote:
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/
>