[Date Prev][Date Next] [Chronological] [Thread] [Top]

Re: Problem with SASL/EXTERNAL authentication from JAVA-program

Martin Pels wrote: 
Hi,

I have an OpenLDAP server running to which I'm trying to connect from a
JAVA-program, using SASL/EXTERNAL with a client certificate.
I'm using the example from
http://forgeftp.novell.com/jldap/checkin/default/unix/samples/SaslExtern
alBind.java.

As the attached log shows I'm getting an error on line 33:

TLS trace: SSL_accept:error in SSLv3 read client certificate A

This is likely the cause of the server returning an error on line 138.

No, the read client certificate error just happens because it wasn't able to read all of the certificate in one try, it eventually succeeds. The error code you get on line 138 is 14, LDAP_SASL_BIND_IN_PROGRESS. That tells you that the server thinks your authentication request isn't complete yet.

The logs show that your client didn't send an authorizationID with the Bind request. I've seen this error before, a lot of LDAP implementors forget to send it. Even if it's unused, at least a zero-length string is supposed to be transmitted.

Compare your log output here with the output from using the ldap* commandline tools, you'll see an extra x04 x00 after the "EXTERNAL" mechanism name, signifying the authzID. Those bytes are missing in your Java client's request. 
Connecting to this server using ldapsearch with SASL/EXTERNAL and the
same client certificate works fine.

Could someone give me a few pointers on where to look on fixing this or
to some JAVA example code that does work?
Thanks in advance.

Regards,
Martin Pels
SARA Computing & Networking Services
High Performance Computing
Tel. +31 (0)20 592 3000
http://www.sara.nl


------------------------------------------------------------------------

1 daemon: select: listen=6 active_threads=0 tvp=NULL
2 daemon: activity on 1 descriptors
3 daemon: activity on: 10r
4 daemon: read activity on 10
5 connection_get(10)
6 connection_get(10): got connid=0
7 connection_read(10): checking for input on id=0
8 TLS trace: SSL_accept:before/accept initialization
9 tls_read: want=11, got=11
10 0000: 80 62 01 03 01 00 39 00 00 00 20 .b....9... 11 tls_read: want=89, got=89
12 0000: 00 00 04 01 00 80 00 00 05 00 00 2f 00 00 33 00 .........../..3. 13 0010: 00 32 00 00 0a 07 00 c0 00 00 16 00 00 13 00 00 .2.............. 14 0020: 09 06 00 40 00 00 15 00 00 12 00 00 03 02 00 80 ...@............ 15 0030: 00 00 08 00 00 14 00 00 11 44 61 9e 77 5c 18 70 .........Da.w\.p 16 0040: 85 a4 51 24 a9 e6 19 ed 5d c7 fb d4 63 40 dc fd ..Q$....]...c@.. 17 0050: 35 be 02 dd 47 31 af da 5c 5...G1..\ 18 TLS trace: SSL_accept:SSLv3 read client hello A
19 TLS trace: SSL_accept:SSLv3 write server hello A
20 TLS trace: SSL_accept:SSLv3 write certificate A
21 tls_write: want=4096, written=4096
22 0000: 16 03 01 00 4a 02 00 00 46 03 01 44 61 9e 77 c8 ....J...F..Da.w. 23 24 [..]


25 0ff0: 30 24 06 03 55 04 03 13 1d 44 46 4e 2d 56 65 72 0$..U....DFN-Ver 26 TLS trace: SSL_accept:SSLv3 write certificate request A
27 tls_write: want=4080, written=4080
28 0000: 65 69 6e 20 55 73 65 72 20 43 41 20 47 72 69 64 ein User CA Grid

29 [..]


30 0fe0: 79 40 70 63 61 2e 64 66 6e 2e 64 65 0e 00 00 00 y@pca.dfn.de.... 31 TLS trace: SSL_accept:SSLv3 flush data
32 tls_read: want=5 error=Resource temporarily unavailable
33 TLS trace: SSL_accept:error in SSLv3 read client certificate A
34 TLS trace: SSL_accept:error in SSLv3 read client certificate A
35 daemon: select: listen=6 active_threads=0 tvp=NULL
36 daemon: activity on 1 descriptors
37 daemon: activity on: 10r
38 daemon: read activity on 10
39 connection_get(10)
40 connection_get(10): got connid=0
41 connection_read(10): checking for input on id=0
42 tls_read: want=5, got=5
43 0000: 16 03 01 0a 38 ....8 44 tls_read: want=2616, got=2616
45 0000: 0b 00 09 ae 00 09 ab 00 04 e5 30 82 04 e1 30 82 ..........0...0.

46 [..]

47 0a30: dd 02 74 5e ce fb 12 f5 ..t^.... 48 TLS certificate verification: depth: 1, err: 0, subject: /C=NL/O=NIKHEF/CN=NIKHEF medium-security certification auth, issuer: /C=NL/O=NIKHEF/CN=NIKHEF medium-security certification auth
49 TLS certificate verification: depth: 0, err: 0, subject: /O=dutchgrid/O=hosts/OU=sara.nl/CN=uni-njs1.sara.nl, issuer: /C=NL/O=NIKHEF/CN=NIKHEF medium-security certification auth
50 TLS trace: SSL_accept:SSLv3 read client certificate A
51 TLS trace: SSL_accept:SSLv3 read client key exchange A
52 tls_read: want=5 error=Resource temporarily unavailable
53 TLS trace: SSL_accept:error in SSLv3 read certificate verify A
54 daemon: select: listen=6 active_threads=0 tvp=NULL
55 daemon: activity on 1 descriptors
56 daemon: activity on: 10r
57 daemon: read activity on 10
58 connection_get(10)
59 connection_get(10): got connid=0
60 connection_read(10): checking for input on id=0
61 tls_read: want=5, got=5
62 0000: 16 03 01 00 86 ..... 63 tls_read: want=134, got=134
64 0000: 0f 00 00 82 00 80 9c 21 a8 59 2b a0 5a 92 73 59 .......!.Y+.Z.sY 65 0010: 99 46 77 b6 99 3e 2a 60 c5 0e 8d 01 64 51 46 24 .Fw..>*`....dQF$ 66 0020: df 41 61 30 be 5b c6 69 df c2 e4 ab c7 e5 7d 7c .Aa0.[.i......}| 67 0030: a8 ef e2 61 a4 43 b8 2a 76 88 78 27 b3 ce b2 eb ...a.C.*v.x'.... 68 0040: d2 1d e0 b3 39 4f aa fd 9a 2f 3c a6 20 07 cc 7c ....9O.../<. ..| 69 0050: 06 2a 07 08 50 71 b3 56 b2 40 8e b2 07 dd 69 ad .*..Pq.V.@....i. 70 0060: 32 f0 13 c1 54 93 b9 c7 b2 26 1a bd c4 7f 8b d8 2...T....&...... 71 0070: 7b 95 d8 d0 95 ff 06 f9 54 bc 1c 1b b8 0a 41 af {.......T.....A. 72 0080: 14 8b 61 f4 10 c7 ..a... 73 TLS trace: SSL_accept:SSLv3 read certificate verify A
74 tls_read: want=5 error=Resource temporarily unavailable
75 TLS trace: SSL_accept:error in SSLv3 read finished A
76 daemon: select: listen=6 active_threads=0 tvp=NULL
77 daemon: activity on 1 descriptors
78 daemon: activity on: 10r
79 daemon: read activity on 10
80 connection_get(10)
81 connection_get(10): got connid=0
82 connection_read(10): checking for input on id=0
83 tls_read: want=5, got=5
84 0000: 14 03 01 00 01 ..... 85 tls_read: want=1, got=1
86 0000: 01 . 87 tls_read: want=5, got=5
88 0000: 16 03 01 00 20 .... 89 tls_read: want=32, got=32
90 0000: 02 59 b7 cf fa b6 62 bc 68 b5 31 ec f0 a1 64 58 .Y....b.h.1...dX 91 0010: 89 02 0e 20 e6 04 42 11 7a a6 61 90 b6 35 ca ea ... ..B.z.a..5.. 92 TLS trace: SSL_accept:SSLv3 read finished A
93 TLS trace: SSL_accept:SSLv3 write change cipher spec A
94 TLS trace: SSL_accept:SSLv3 write finished A
95 tls_write: want=43, written=43
96 0000: 14 03 01 00 01 01 16 03 01 00 20 b1 f0 63 0b ff .......... ..c.. 97 0010: 41 0c 3c ec 2d b6 43 e5 a8 39 9b 45 1a e4 d8 43 A.<.-.C..9.E...C 98 0020: 90 33 bf bf 8d 4a ab 4f f4 0b 9d .3...J.O... 99 TLS trace: SSL_accept:SSLv3 flush data
100 => ldap_dn2bv(16)
101 ldap_err2string
102 <= ldap_dn2bv(cn=uni-njs1.sara.nl,ou=sara.nl,o=hosts,o=dutchgrid)=0 Success
103 daemon: select: listen=6 active_threads=0 tvp=NULL
104 daemon: activity on 1 descriptors
105 daemon: activity on: 10r
106 daemon: read activity on 10
107 connection_get(10)
108 connection_get(10): got connid=0
109 connection_read(10): checking for input on id=0
110 ber_get_next
111 tls_read: want=5, got=5
112 0000: 17 03 01 00 28 ....( 113 tls_read: want=40, got=40
114 0000: 96 95 c6 10 7c b1 5c 9f 37 e5 8f 7f 3c 04 b9 6e ....|.\.7...<..n 115 0010: d5 e0 db 0c a2 a1 37 41 03 1f 61 aa 3b 51 54 57 ......7A..a.;QTW 116 0020: c5 59 0f da d0 69 61 3c .Y...ia< 117 ldap_read: want=8, got=8
118 0000: 30 16 02 01 01 60 11 02 0....`.. 119 ldap_read: want=16, got=16
120 0000: 01 03 04 00 a3 0a 04 08 45 58 54 45 52 4e 41 4c ........EXTERNAL 121 ber_get_next: tag 0x30 len 22 contents:
122 ber_get_next
123 tls_read: want=5 error=Resource temporarily unavailable
124 ldap_read: want=8 error=Resource temporarily unavailable
125 ber_get_next on fd 10 failed errno=11 (Resource temporarily unavailable)
126 daemon: select: listen=6 active_threads=0 tvp=NULL
127 daemon: activity on 1 descriptors
128 daemon: select: listen=6 active_threads=0 tvp=NULL
129 do_bind
130 ber_scanf fmt ({imt) ber:
131 ber_scanf fmt ({m) ber:
132 ber_scanf fmt (}}) ber:
133 >>> dnPrettyNormal: <>
134 <<< dnPrettyNormal: <>, <>
135 do_sasl_bind: dn () mech EXTERNAL
136 ==> sasl_bind: dn="" mech=EXTERNAL datalen=0
137 send_ldap_sasl: err=14 len=0
138 send_ldap_response: msgid=1 tag=97 err=14
139 ber_flush: 16 bytes to sd 10
140 0000: 30 0e 02 01 01 61 09 0a 01 0e 04 00 04 00 87 00 0....a.......... 141 tls_write: want=37, written=37
142 0000: 17 03 01 00 20 a7 00 21 5f 88 90 f3 3c cc 78 be .... ..!_...<.x. 143 0010: 19 a1 51 b1 bc 1d 32 e5 e1 6a 03 98 c6 69 02 41 ..Q...2..j...i.A 144 0020: 06 dd bc 88 3a ....: 145 ldap_write: want=16, written=16
146 0000: 30 0e 02 01 01 61 09 0a 01 0e 04 00 04 00 87 00 0....a.......... 147 <== slap_sasl_bind: rc=14
148 daemon: activity on 1 descriptors
149 daemon: activity on: 10r
150 daemon: read activity on 10
151 connection_get(10)
152 connection_get(10): got connid=0
153 connection_read(10): checking for input on id=0
154 ber_get_next
155 tls_read: want=5, got=0


156 ldap_read: want=8, got=0


157 ber_get_next on fd 10 failed errno=0 (Success)
158 connection_read(10): input error=-2 id=0, closing.
159 connection_closing: readying conn=0 sd=10 for close
160 connection_close: conn=0 sd=10
161 daemon: removing 10
162 tls_write: want=23, written=23
163 0000: 15 03 01 00 12 2a db 02 cf f6 17 e1 b8 ab dd 7c .....*.........| 164 0010: 7b e4 42 5b 06 b1 d2 {.B[... 165 TLS trace: SSL3 alert write:warning:close notify
166 daemon: select: listen=6 active_threads=0 tvp=NULL
167 daemon: activity on 1 descriptors
168 daemon: select: listen=6 active_threads=0 tvp=NULL
169 daemon: shutdown requested and initiated.
170 daemon: closing 6
171 slapd shutdown: waiting for 0 threads to terminate
172 slapd shutdown: initiated
173 ====> bdb_cache_release_all
174 slapd shutdown: freeing system resources.
175 slapd stopped.


--
 -- Howard Chu
 Chief Architect, Symas Corp.  http://www.symas.com
 Director, Highland Sun        http://highlandsun.com/hyc
 OpenLDAP Core Team            http://www.openldap.org/project/