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/