[389-users] Random failures on startTLS

Wed Apr 14 17:17:22 UTC 2010

>
> What is the platform?

Linux CentOS 5.4 i386

> What is the 389 version?

 rpm -qi 389-ds-base
>

Name        : 389-ds-base                  Relocations: (not relocatable)
Version     : 1.2.5                             Vendor: Fedora Project
Release     : 1.el5                         Build Date: Tue 12 Jan 2010
02:35:50 PM CST
Install Date: Wed 17 Mar 2010 03:54:26 PM CDT      Build Host:
x86-04.phx2.fedoraproject.org
Group       : System Environment/Daemons    Source RPM:
389-ds-base-1.2.5-1.el5.src.rpm
Size        : 5216698                          License: GPLv2 with
exceptions
Signature   : DSA/SHA1, Wed 13 Jan 2010 11:33:44 AM CST, Key ID
119cc036217521f6
Packager    : Fedora Project
URL         : http://port389.org/
Summary     : 389 Directory Server (base)
Description :
389 Directory Server is an LDAPv3 compliant server.  The base package
includes
the LDAP server and command line utilities for server administration.

What is the client?  JNDI?

Yes JNDI.  Here is a code snippet of what is happening:

           ctx = new InitialLdapContext(env, null);

            // Changing the connection to use SSL/TLS
            tls = (StartTlsResponse)ctx.extendedOperation(new
StartTlsRequest());
            tlsSession = tls.negotiate();

            PasswordChangeRequest req = new PasswordChangeRequest(dn,
oldPassword, newPassword);
            PasswordChangeResponse resp =
(PasswordChangeResponse)ctx.extendedOperation(req);

> The log item ABANDON targetop=NOTFOUND
> msgid=11 is interesting

I thought this wasn't that interesting because it was a different connection
there were actually a few of those so if it helps, here are the rest related
to that connection around the same time:

14/Apr/2010:08:27:55 -0500] conn=3007 fd=65 slot=65 connection from
127.0.0.1 to 127.0.0.1
[14/Apr/2010:08:27:55 -0500] conn=3007 op=0 BIND
dn="cn=Manager,dc=hranet,dc=org" method=128 version=3
[14/Apr/2010:08:27:55 -0500] conn=3007 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=manager,dc=hranet,dc=org"
[14/Apr/2010:08:27:55 -0500] conn=3007 op=1 SRCH base="dc=hranet,dc=org"
scope=2 filter="(&(uid=microprocessor)(objectClass=user))" attrs=ALL
[14/Apr/2010:08:27:55 -0500] conn=3007 op=1 RESULT err=0 tag=101 nentries=0
etime=0
[14/Apr/2010:08:27:55 -0500] conn=3007 op=2 ADD
dn="uid=microprocessor,ou=employees,ou=people,dc=hranet,dc=org"
[14/Apr/2010:08:27:55 -0500] conn=3007 op=2 RESULT err=0 tag=105 nentries=0
etime=0 csn=4bc5c2db000000170000
[14/Apr/2010:08:27:55 -0500] conn=3007 op=3 MOD
dn="uid=microprocessor,ou=employees,ou=people,dc=hranet,dc=org"
[14/Apr/2010:08:27:55 -0500] conn=3007 op=3 RESULT err=0 tag=103 nentries=0
etime=0 csn=4bc5c2db000100170000
[14/Apr/2010:08:27:55 -0500] conn=3007 op=4 SRCH base="dc=hranet,dc=org"
scope=2 filter="(uid=microprocessor)" attrs=ALL
[14/Apr/2010:08:27:55 -0500] conn=3007 op=4 RESULT err=0 tag=101 nentries=1
etime=0
[14/Apr/2010:08:27:55 -0500] conn=3007 op=5 ABANDON targetop=NOTFOUND
msgid=5
[14/Apr/2010:08:27:55 -0500] conn=3007 op=6 SRCH base="dc=hranet,dc=org"
scope=2 filter="(&(uid=6224)(objectClass=user))" attrs=ALL
[14/Apr/2010:08:27:55 -0500] conn=3007 op=8 RESULT err=0 tag=101 nentries=1
etime=0
[14/Apr/2010:08:27:55 -0500] conn=3007 op=9 ABANDON targetop=NOTFOUND
msgid=9
[14/Apr/2010:08:27:55 -0500] conn=3007 op=10 SRCH base="dc=hranet,dc=org"
scope=2 filter="(uid=microprocessor)" attrs=ALL
[14/Apr/2010:08:27:55 -0500] conn=3007 op=10 RESULT err=0 tag=101 nentries=1
etime=0
[14/Apr/2010:08:27:55 -0500] conn=3008 fd=66 slot=66 connection from
127.0.0.1 to 127.0.0.1
[14/Apr/2010:08:27:55 -0500] conn=3007 op=11 ABANDON targetop=NOTFOUND
msgid=11
[14/Apr/2010:08:27:55 -0500] conn=3008 op=0 BIND
dn="cn=Manager,dc=hranet,dc=org" method=128 version=3
[14/Apr/2010:08:27:55 -0500] conn=3008 op=1 EXT oid="1.3.6.1.4.1.1466.20037"
name="startTLS"
[14/Apr/2010:08:27:55 -0500] conn=3008 op=1 RESULT err=1 tag=120 nentries=0
etime=0
[14/Apr/2010:08:27:55 -0500] conn=3008 op=2 UNBIND
[14/Apr/2010:08:27:55 -0500] conn=3008 op=2 fd=66 closed - U1
[14/Apr/2010:08:27:55 -0500] conn=3008 op=0 RESULT err=0 tag=97 nentries=0
etime=0 dn="cn=manager,dc=hranet,dc=org"
[14/Apr/2010:08:28:02 -0500] conn=3003 op=17 UNBIND
[14/Apr/2010:08:28:02 -0500] conn=3003 op=17 fd=67 closed - U1
[14/Apr/2010:08:28:02 -0500] conn=3007 op=12 SRCH base="dc=hranet,dc=org"
scope=2 filter="(uid=peter)" attrs=ALL
[14/Apr/2010:08:28:02 -0500] conn=3007 op=12 RESULT err=0 tag=101 nentries=1
etime=0

Thanks,

Aaron Hagopian
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.fedoraproject.org/pipermail/389-users/attachments/20100414/22c3944c/attachment.html>