[389-users] "failed to decode ldap controls" with 1.2.10.2

[Colin Panisset]

I have two different servers, one installed recently (as in, earlier
this week), and one that's been operating fine for more than a year.

The new server is Centos 6.3, with 389-ds-base 1.2.10.2
The old server is Centos 5.5, with 389-ds-base 1.2.9.9

When I attempt to authenticate from an appliance which uses the Ruby
Net::LDAP gem to the old server (via plain LDAP, no SSL), I have no
problems, but when I switch out the old server for the new, I have auth
failures. Other LDAP clients do not exhibit this problem eg ldapsearch,
nslcd, etc)

The logs on the old (working) auth server show:

> [16/Aug/2012:14:16:52 +1000] conn=18453477 fd=576 slot=576 connection from 172.1.2.3 to 172.1.2.4
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=0 BIND dn="" method=128 version=3
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn=""
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=1 SRCH base="dc=example" scope=2 filter="(uid=abc)" attrs=ALL
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=1 RESULT err=0 tag=101 nentries=1 etime=0
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=2 BIND dn="cn=Some User,ou=people,dc=example" method=128 version=3
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=2 RESULT err=0 tag=97 nentries=0 etime=0 dn="cn=some user,ou=people,dc=example"
> [16/Aug/2012:14:16:52 +1000] conn=18453477 op=-1 fd=576 closed - B1

The logs on the new auth server show:

> [16/Aug/2012:09:12:45 +1000] conn=2897 fd=67 slot=67 connection from 172.1.2.3 to 172.1.2.5
> [16/Aug/2012:09:12:45 +1000] conn=2897 op=0 BIND dn="" method=128 version=3
> [16/Aug/2012:09:12:45 +1000] conn=2897 op=0 RESULT err=0 tag=97 nentries=0 etime=0 dn=""
> [16/Aug/2012:09:12:45 +1000] conn=2897 op=1 SRCH base="" scope=2 filter="(uid=abc)", failed to decode LDAP controls
> [16/Aug/2012:09:12:45 +1000] conn=2897 op=1 RESULT err=2 tag=101 nentries=0 etime=0
> [16/Aug/2012:09:12:45 +1000] conn=2897 op=-1 fd=67 closed - B1

Now, a tcpdump of the search queries shows that both search request
packets from the Net::LDAP appliance are *identical* (except for the
origin port, MAC addresses, etc), but not *quite* the same as the same
query initiated through command-line ldapsearch.

Here's a dump of a request packet from ldapsearch:

> 	0x0000:  4500 0074 7882 4000 3f06 6389 ac19 0005  E..tx. at .?.c.....
> 	0x0010:  ac19 0741 e04a 0185 a6ec 4d60 1c36 5d68  ...A.J....M`.6]h
> 	0x0020:  8018 006c d087 0000 0101 080a 0ab9 209a  ...l............
> 	0x0030:  053b 1109 303e 0201 0263 3904 1a64 633d  .;..0>...c9..dc=
> 	0x0040:  xxxx xxxx xxxx xxxx xxxx 2c64 633d xxxx  xxxxxxxxxx,dc=xx
> 	0x0050:  xx2c 6463 3dxx xx0a 0102 0a01 0002 0100  x,dc=xx.........
> 	0x0060:  0201 0001 0100 a30a 0403 7569 6404 03xx  ..........uid..x
> 	0x0070:  xxxx 3000                                xx0.

and one from the Net::LDAP appliance:

> 0000           0024 e865 82bf 021b  21c6 b3c8 0800 4500   .$.e....!.....E.
> 0010           006a 1256 4000 4006  c8c3 ac19 0002 ac19   .j.V at .@.........
> 0020           0740 7c26 0185 3666  7186 f3bd ce0d 5018   .@|&..6fq.....P.
> 0030           3908 daef 0000 3040  0201 0263 3904 1a64   9.....0 at ...c9..d
> 0040           633d 7265 616c 6573  7461 7465 2c64 633d   c=xxxxxxxxxx,dc=
> 0050           636f 6d2c 6463 3d61  750a 0102 0a01 0002   xxx,dc=xx.......
> 0060           0101 0201 0001 0100  a30a 0403 7569 6404   ............uid.
> 0070           0363 6d70 3000 a000                        .xxx0...  

I note that the ldapsearch query uses:

LDAPMessage ::= SEQUENCE {              // 0x30 0x3e

while the Net::LDAP query uses:

LDAPMessage ::= SEQUENCE OF Control {   // 0x30 0x40

in the PDU -- look at bytes 0x34 and 0x35 in the ldapsearch packet, and
at bytes 0x36 and 0x37 in the Net::LDAP packet.

Is 389-ds behaving correctly in this case, and the Net::LDAP gem is
wrong? Or is this a regression in 389-ds?

-- 
Colin Panisset
Senior Systems Engineer, REA Group
Ph: +61 (0)3 8456 4636 Mb: +61 (0) 457 788 259