[389-users] Random failures on startTLS
Rich Megginson
rmeggins at redhat.com
Wed Apr 14 17:41:42 UTC 2010
Aaron Hagopian wrote:
>
> 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 <http://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
Can you provide a small test JNDI program that reproduces this problem?
I believe it is a bug in the server, and has something to do with the
ABANDON requests not being cleaned up properly, even though the ops are
for a different connection.
> ------------------------------------------------------------------------
>
> --
> 389 users mailing list
> 389-users at lists.fedoraproject.org
> https://admin.fedoraproject.org/mailman/listinfo/389-users
More information about the 389-users
mailing list