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

Wed Mar 22 18:12:25 UTC 2017

On 10/03/17 16:24, Rob Crittenden wrote:
> lejeczek wrote:
>>
>> On 06/03/17 20:11, Rob Crittenden wrote:
>>> lejeczek wrote:
>>>> 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.
>>> 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?
> 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