[Freeipa-users] slapi_ldap_bind - Error: could not send startTLS request

Discussion:

lejeczek

2017-03-04 14:47:32 UTC

hi everyone
I've seemingly finely working domain, I mean it all seem
fine to me, except for:

[04/Mar/2017:14:26:47.439218725 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:26:47.441155853 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:31:47.454016982 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:31:47.482477473 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:36:46.458508994 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:36:46.479878884 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:41:47.389700728 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:41:47.394379376 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)

being logged quite frequently, as you can see. Setup:

ipa-client-4.4.0-14.el7.centos.4.x86_64
ipa-client-common-4.4.0-14.el7.centos.4.noarch
ipa-common-4.4.0-14.el7.centos.4.noarch
ipa-python-compat-4.4.0-14.el7.centos.4.noarch
ipa-server-4.4.0-14.el7.centos.4.x86_64
ipa-server-common-4.4.0-14.el7.centos.4.noarch
ipa-server-dns-4.4.0-14.el7.centos.4.noarch

Replication, users, logins, all seem normal. But above
bothers me as I am afraid it may one day turn out critical
and brake stuff down.
This is on the first server that initiated the domain, long
time ago.
There is a second server which logs the same, but only a few
entries then goes quiet.
Third server's error log is completely free from this error.

Would appreciate all help.
L

lejeczek

2017-03-06 10:38:14 UTC

Permalink

Post by lejeczek
hi everyone
I've seemingly finely working domain, I mean it all seem
[04/Mar/2017:14:26:47.439218725 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:26:47.441155853 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:31:47.454016982 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:31:47.482477473 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:36:46.458508994 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:36:46.479878884 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:41:47.389700728 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
[04/Mar/2017:14:41:47.394379376 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
ipa-client-4.4.0-14.el7.centos.4.x86_64
ipa-client-common-4.4.0-14.el7.centos.4.noarch
ipa-common-4.4.0-14.el7.centos.4.noarch
ipa-python-compat-4.4.0-14.el7.centos.4.noarch
ipa-server-4.4.0-14.el7.centos.4.x86_64
ipa-server-common-4.4.0-14.el7.centos.4.noarch
ipa-server-dns-4.4.0-14.el7.centos.4.noarch
Replication, users, logins, all seem normal. But above
bothers me as I am afraid it may one day turn out critical
and brake stuff down.
This is on the first server that initiated the domain,
long time ago.
There is a second server which logs the same, but only a
few entries then goes quiet.
Third server's error log is completely free from this error.
Would appreciate all help.
L

As I was afraid... more. I'm adding a replica, with
arguments: --setup-dns --no-forwarders . This seems to have
succeeded:
...
Configured /etc/ssh/sshd_config
Configuring private.ccnr.ceb.private.cam.ac.uk as NIS domain.
Client configuration complete.

but on the master(fist server in the domain) during replica
installation I see:

[06/Mar/2017:09:56:01.022636856 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389): The
remote replica has a different database generation ID than
the local database. You may have to reinitialize the remote
replica, or the local replica.
[06/Mar/2017:09:56:01.900679757 +0000] NSMMReplicationPlugin
- Beginning total update of replica
"agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389)".
[06/Mar/2017:09:56:05.287761359 +0000] NSMMReplicationPlugin
- Finished total update of replica
"agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389)".
Sent 799 entries.
[06/Mar/2017:09:56:15.293584156 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389):
Unable to receive the response for a startReplication
extended operation to consumer (Can't contxx. LDAP server).
Will retry later.
[06/Mar/2017:09:56:19.220334467 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389):
Replication bind with SIMPLE auth resumed
[06/Mar/2017:09:56:24.523570143 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389):
Replication bind with GSSAPI auth failed: LDAP error 49
(Invalid credentials) ()
[06/Mar/2017:09:56:46.295504003 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389):
Replication bind with GSSAPI auth failed: LDAP error -1
(Can't contxx. LDAP server) ()
...
[06/Mar/2017:09:57:57.620175772 +0000] NSMMReplicationPlugin
- agmt="cn=meToswir.priv.xx.xx.priv.xx.xx.x. (swir:389):
Replication bind with GSSAPI auth resumed
[06/Mar/2017:10:01:46.442346796 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
cloneAgreement1-swir.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)
[06/Mar/2017:10:01:46.452580492 +0000] NSMMReplicationPlugin
-
agmt="cn=masterAgreement1-swir.priv.xx.xx.priv.xx.xx.x.pki-tomcat"
(swir:389): Replication bind with SIMPLE auth failed: LDAP
error 32 (No such object) ()
[06/Mar/2017:10:01:46.454557885 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
masterAgreement1-rider.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)
[06/Mar/2017:10:01:46.456463238 +0000] NSMMReplicationPlugin
-
agmt="cn=cloneAgreement1-rider.priv.xx.xx.priv.xx.xx.x.pki-tomcat"
(swir:389): Replication bind with SIMPLE auth failed: LDAP
error 32 (No such object) ()
Configured /etc/ssh/sshd_config
Configuring priv.xx.xx.priv.xx.xx.x.as NIS domain.
[06/Mar/2017:10:06:46.708910487 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
cloneAgreement1-swir.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)

and on the other(third replica server):
...
[06/Mar/2017:09:59:32.505421711 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
masterAgreement1-dzien.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)
[06/Mar/2017:09:59:32.511853210 +0000] NSMMReplicationPlugin
-
agmt="cn=cloneAgreement1-dzien.priv.xx.xx.priv.xx.xx.x.pki-tomcat"
(swir:389): Replication bind with SIMPLE auth failed: LDAP
error 32 (No such object) ()
[06/Mar/2017:10:04:31.881879230 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
masterAgreement1-dzien.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)
[06/Mar/2017:10:09:31.775183433 +0000] slapi_ldap_bind -
Error: could not bind id [cn=Replication Manager
masterAgreement1-dzien.priv.xx.xx.priv.xx.xx.x.pki-tomcat,ou=csusers,cn=config]
authentication mechanism [SIMPLE]: error 32 (No such object)
errno 0 (Success)
...

...

Rob Crittenden

2017-03-06 20:11:11 UTC

Permalink

Post by lejeczek
hi everyone
I've seemingly finely working domain, I mean it all seem fine to me,
[04/Mar/2017:14:26:47.439218725 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:26:47.441155853 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:31:47.454016982 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:31:47.482477473 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:36:46.458508994 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:36:46.479878884 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:41:47.389700728 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
[04/Mar/2017:14:41:47.394379376 +0000] slapi_ldap_bind - Error: could
not send startTLS request: error -1 (Can't contact LDAP server) errno
107 (Transport endpoint is not connected)
ipa-client-4.4.0-14.el7.centos.4.x86_64
ipa-client-common-4.4.0-14.el7.centos.4.noarch
ipa-common-4.4.0-14.el7.centos.4.noarch
ipa-python-compat-4.4.0-14.el7.centos.4.noarch
ipa-server-4.4.0-14.el7.centos.4.x86_64
ipa-server-common-4.4.0-14.el7.centos.4.noarch
ipa-server-dns-4.4.0-14.el7.centos.4.noarch
Replication, users, logins, all seem normal. But above bothers me as I
am afraid it may one day turn out critical and brake stuff down.
This is on the first server that initiated the domain, long time ago.
There is a second server which logs the same, but only a few entries
then goes quiet.
Third server's error log is completely free from this error.
Would appreciate all help.

The CA replication agreements are handled by ipa-csreplica-manage. You
may have leftover agreements from previous installs there.

rob

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

lejeczek

2017-03-07 21:37:58 UTC

Permalink

Post by Rob Crittenden

The CA replication agreements are handled by ipa-csreplica-manage. You
may have leftover agreements from previous installs there.
rob

many thanks,
should I be searching through ldap tree? If yes then where
more less?
$ ipa-csreplica-manage list
shows only two servers, which would make sense, would add
up, I think.

lejeczek

2017-03-07 21:48:59 UTC

Permalink

Post by Rob Crittenden

The CA replication agreements are handled by ipa-csreplica-manage. You
may have leftover agreements from previous installs there.
rob

I'm afraid I let over the years for some bits in the domain
gone haywire. I found this:

dn: cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ca
objectClass: nsContainer
objectClass: top

dn:
cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: certprofiles
objectClass: nsContainer
objectClass: top

dn: cn=caacls,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: caacls
objectClass: nsContainer
objectClass: top

dn:
cn=cas+nsuniqueid=647ed0b1-b70911e6-b84df1c7-2176fa48,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: cas
objectClass: nsContainer
objectClass: top

dn: cn=cas,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: cas
objectClass: nsContainer
objectClass: top

dn:
cn=IECUserRoles,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
description: User profile that includes IECUserRoles
extension from request
ipaCertProfileStoreIssued: TRUE
cn: IECUserRoles
objectClass: ipacertprofile
objectClass: top

dn:
cn=caIPAserviceCert,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
description: Standard profile for network services
ipaCertProfileStoreIssued: TRUE
cn: caIPAserviceCert
objectClass: ipacertprofile
objectClass: top

dn:
ipaUniqueID=1ea0be16-fc01-11e5-a664-f04da240c1d2,cn=caacls,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
ipaMemberCertProfile:
cn=caIPAserviceCert,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
ipaUniqueID: 1ea0be16-fc01-11e5-a664-f04da240c1d2
ipaEnabledFlag: TRUE
hostCategory: all
objectClass: ipaassociation
objectClass: ipacaacl
cn: hosts_services_caIPAserviceCert
serviceCategory: all

dn:
cn=ipa,cn=cas+nsuniqueid=647ed0b1-b70911e6-b84df1c7-2176fa48,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ipa
ipaCaId: 0725f730-9351-4115-aa68-ecb2f47dd805
ipaCaSubjectDN: CN=Certificate
Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
objectClass: top
objectClass: ipaca
ipaCaIssuerDN: CN=Certificate
Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
description: IPA CA

dn:
cn=ipa,cn=cas,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ipa
ipaCaId: ed1bbc62-45c5-4d4a-96fb-0c16129dbad0
ipaCaSubjectDN: CN=Certificate
Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
objectClass: top
objectClass: ipaca
ipaCaIssuerDN: CN=Certificate
Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
description: IPA CA

is this the culprit?
b.w.
L.

Rob Crittenden

2017-03-10 16:24:33 UTC

Permalink

Post by Rob Crittenden

The CA replication agreements are handled by ipa-csreplica-manage. You
may have leftover agreements from previous installs there.
rob

I'm afraid I let over the years for some bits in the domain gone
dn: cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ca
objectClass: nsContainer
objectClass: top
dn: cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: certprofiles
objectClass: nsContainer
objectClass: top
dn: cn=caacls,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: caacls
objectClass: nsContainer
objectClass: top
cn=cas+nsuniqueid=647ed0b1-b70911e6-b84df1c7-2176fa48,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: cas
objectClass: nsContainer
objectClass: top
dn: cn=cas,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: cas
objectClass: nsContainer
objectClass: top
cn=IECUserRoles,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
description: User profile that includes IECUserRoles extension from request
ipaCertProfileStoreIssued: TRUE
cn: IECUserRoles
objectClass: ipacertprofile
objectClass: top
cn=caIPAserviceCert,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
description: Standard profile for network services
ipaCertProfileStoreIssued: TRUE
cn: caIPAserviceCert
objectClass: ipacertprofile
objectClass: top
ipaUniqueID=1ea0be16-fc01-11e5-a664-f04da240c1d2,cn=caacls,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn=caIPAserviceCert,cn=certprofiles,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
ipaUniqueID: 1ea0be16-fc01-11e5-a664-f04da240c1d2
ipaEnabledFlag: TRUE
hostCategory: all
objectClass: ipaassociation
objectClass: ipacaacl
cn: hosts_services_caIPAserviceCert
serviceCategory: all
cn=ipa,cn=cas+nsuniqueid=647ed0b1-b70911e6-b84df1c7-2176fa48,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ipa
ipaCaId: 0725f730-9351-4115-aa68-ecb2f47dd805
ipaCaSubjectDN: CN=Certificate Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
objectClass: top
objectClass: ipaca
ipaCaIssuerDN: CN=Certificate Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
description: IPA CA
dn: cn=ipa,cn=cas,cn=ca,dc=priv,dc=xx.dc=xx.dc=priv,dc=xx,dc=xx,dc=x
cn: ipa
ipaCaId: ed1bbc62-45c5-4d4a-96fb-0c16129dbad0
ipaCaSubjectDN: CN=Certificate Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
objectClass: top
objectClass: ipaca
ipaCaIssuerDN: CN=Certificate Authority,O=PRIVATE.xx.xx.PRIVATE.xx.xx.x
description: IPA CA
is this the culprit?

You have some replication conflict entries in there. I see no way how
this could affect a connection issue though it is something you should
clean up.

I'd use tcpdump/wireshark to see what is going on. It will show you if
it is a simple connection failure or an SSL handshake failure.

rob

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project

lejeczek

2017-03-22 18:12:25 UTC

Permalink

Post by Rob Crittenden

The CA replication agreements are handled by ipa-csreplica-manage. You
may have leftover agreements from previous installs there.
rob

You have some replication conflict entries in there. I see no way how
this could affect a connection issue though it is something you should
clean up.
I'd use tcpdump/wireshark to see what is going on. It will show you if
it is a simple connection failure or an SSL handshake failure.
rob

tcpdump shows this(snippet):

18:07:13.181976 IP 10.5.6.100.37860 > 10.5.6.49.ldap: Flags
[.], ack 3661, win 266, options [nop,nop,TS val 942379968
ecr 522552901], length 0
18:07:13.182234 IP 10.5.6.49.49750 > 10.5.6.100.ldap: Flags
[.], ack 4260, win 288, options [nop,nop,TS val 522557957
ecr 942369708], length 0
18:07:13.182337 IP 10.5.6.49.ldap > 10.5.6.100.37860: Flags
[.], ack 2392, win 253, options [nop,nop,TS val 522557957
ecr 942369772], length 0
[22/Mar/2017:18:01:50.979626277 +0000] slapi_ldap_bind -
Error: could not send startTLS request: error -1 (Can't
contact LDAP server) errno 107 (Transport endpoint is not
connected)
18:07:18.237961 IP 10.5.6.100.ldap > 10.5.6.49.49750: Flags
[.], ack 3627, win 278, options [nop,nop,TS val 942385024
ecr 522557957], length 0
18:07:18.237964 IP 10.5.6.100.37860 > 10.5.6.49.ldap: Flags
[.], ack 3661, win 266, options [nop,nop,TS val 942385024
ecr 522557957], length 0

I wonder if it is possible to make slapd log a bit more..
telling?

Does the snippet shed any light on what is working wrong?
(I'll be a novice tcpdumper)

b.w.
L

--
Manage your subscription for the Freeipa-users mailing list:
https://www.redhat.com/mailman/listinfo/freeipa-users
Go to http://freeipa.org for more info on the project