Issue 8048 - back-sock/slapo-sock issue
Summary: back-sock/slapo-sock issue
Status: VERIFIED FIXED
Alias: None
Product: OpenLDAP
Classification: Unclassified
Component: slapd (show other issues)
Version: unspecified
Hardware: All All
: --- normal
Target Milestone: ---
Assignee: OpenLDAP project
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-02-03 10:24 UTC by Howard Chu
Modified: 2015-07-02 17:48 UTC (History)
0 users

See Also:


Attachments
string (1.87 KB, text/plain)
2015-06-30 17:39 UTC, Michael Ströder
Details

Note You need to log in before you can comment on or make changes to this issue.
Description Howard Chu 2015-02-03 10:24:35 UTC
Full_Name: Howard Chu
Version: 2.4
OS: 
URL: ftp://ftp.openldap.org/incoming/
Submission from: (NULL) (110.49.207.42)
Submitted by: hyc


The result parser is checking for CONTINUE in the wrong place.
Comment 1 Howard Chu 2015-02-03 10:36:28 UTC
changed notes
changed state Open to Test
moved from Incoming to Software Bugs
Comment 2 Quanah Gibson-Mount 2015-02-06 17:11:18 UTC
changed notes
changed state Test to Release
Comment 3 Michael Ströder 2015-06-29 13:44:03 UTC
hyc@openldap.org wrote:
> Full_Name: Howard Chu
> Version: 2.4
> OS: 
> URL: ftp://ftp.openldap.org/incoming/
> Submission from: (NULL) (110.49.207.42)
> Submitted by: hyc
> 
> The result parser is checking for CONTINUE in the wrong place.

Please re-open this ticket. RE24 (tagged as 2.4.41) made things worse.

Is there a chance to get things fixed? I promise to help testing.

First CONTINUE\n works in RE24 better than in 2.4.40 which was the cause of
this ITS.

But handling RESULT is seriously broken, even more than in 2.4.40.

Example:

This is my Python response string:

'RESULT\nmsgid: 1\ncode: 49\ninfo: remote NOK\n\n'

This leads to slapd debug output:

55914b01 str2result (msgid: 1
code: 49
info: remote NOK

) unknown
55914b01 str2result (
) unknown

Note that the whole string is returned as being unknown.

Also with 2.4.40 my client script receives ' remote NOK' as diagnostic
message. With RE24 the diagnostic message is complete garbage.

So I tried many response string variants regarding number of \n and leaving
away space after the colon etc. But not really working.

Sometimes slapd hangs, sometimes my client hangs e.g. when sending two
subsequent bind requests in one open LDAP connection.



Comment 4 Michael Ströder 2015-06-29 15:16:35 UTC
Michael Ströder wrote:
> This is my Python response string:
> 
> 'RESULT\nmsgid: 1\ncode: 49\ninfo: remote NOK\n\n'

Hmmpf! After adding null-bytes in each line like this

'RESULT\n\x00msgid: 1\n\x00code: 49\n\x00\n\x00'

at least this message went away also with RE24:

> This leads to slapd debug output:
> 
> 55914b01 str2result (msgid: 1
> code: 49
> info: remote NOK
> 
> ) unknown
> 55914b01 str2result (
> ) unknown


Null-bytes really needed? str2result() checks for null-bytes in a bunch of
cases. I really wonder why null-terminated  char *s is used.

Ciao, Michael.


Comment 5 Michael Ströder 2015-06-29 16:45:11 UTC
michael@stroeder.com wrote:
> Null-bytes really needed?

Hmm, with null-bytes the wrong result code is returned to the LDAP client.

Without null-bytes the correct result code is returned to the client but slapd
complains about unknown string:

'RESULT\nmsgid: 1\ncode: 49\nmatched: uid=wuqww,cn=ampua,ou=ampua\ninfo: NOK\n\n'

results in log message:

559174df str2result (msgid: 1
code: 0

) unknown
559174df str2result (
) unknown



Comment 6 Howard Chu 2015-06-29 17:15:56 UTC
michael@stroeder.com wrote:
> michael@stroeder.com wrote:
>> Null-bytes really needed?
>
> Hmm, with null-bytes the wrong result code is returned to the LDAP client.
>
> Without null-bytes the correct result code is returned to the client but slapd
> complains about unknown string:
>
> 'RESULT\nmsgid: 1\ncode: 49\nmatched: uid=wuqww,cn=ampua,ou=ampua\ninfo: NOK\n\n'
>
> results in log message:
>
> 559174df str2result (msgid: 1
> code: 0
>
> ) unknown
> 559174df str2result (
> ) unknown

I would almost suspect you were running on Windows. None of the behavior 
you're reporting occurs for me using the searchexample.pl script. Sounds like 
your problem is a python runtime configuration, not a slapd bug.

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

Comment 7 Michael Ströder 2015-06-29 20:06:45 UTC
Howard Chu wrote:
> michael@stroeder.com wrote:
>> michael@stroeder.com wrote:
>>> Null-bytes really needed?
>>
>> Hmm, with null-bytes the wrong result code is returned to the LDAP client.
>>
>> Without null-bytes the correct result code is returned to the client but slapd
>> complains about unknown string:
>>
>> 'RESULT\nmsgid: 1\ncode: 49\nmatched: uid=wuqww,cn=ampua,ou=ampua\ninfo:
>> NOK\n\n'
>>
>> results in log message:
>>
>> 559174df str2result (msgid: 1
>> code: 0
>>
>> ) unknown
>> 559174df str2result (
>> ) unknown
> 
> I would almost suspect you were running on Windows. None of the behavior
> you're reporting occurs for me using the searchexample.pl script.

Your script does not return any real 'RESULT..' responses.
I also have less issues when just returning 'CONTINUE\n'.

> Sounds like your problem is a python runtime configuration, not a slapd
> bug.

Not on Windows and no run-time configuration involved.

Look at the raw string representations I've posted. That string goes directly
to SocketServer.BaseRequestHandler.request.sendall(response_str).

Can I raise the debug level? Log level trace does not really show the original
byte sequence received by the external listener.

Ciao, Michael.


Comment 8 Howard Chu 2015-06-30 12:20:24 UTC
michael@stroeder.com wrote:
> Howard Chu wrote:
>> michael@stroeder.com wrote:
>>> michael@stroeder.com wrote:
>>>> Null-bytes really needed?
>>>
>>> Hmm, with null-bytes the wrong result code is returned to the LDAP cli=
> ent.
>>>
>>> Without null-bytes the correct result code is returned to the client b=
> ut slapd
>>> complains about unknown string:
>>>
>>> 'RESULT\nmsgid: 1\ncode: 49\nmatched: uid=3Dwuqww,cn=3Dampua,ou=3Dampu=
> a\ninfo:
>>> NOK\n\n'
>>>
>>> results in log message:
>>>
>>> 559174df str2result (msgid: 1
>>> code: 0
>>>
>>> ) unknown
>>> 559174df str2result (
>>> ) unknown
>> =20
>> I would almost suspect you were running on Windows. None of the behavio=
> r
>> you're reporting occurs for me using the searchexample.pl script.
>
> Your script does not return any real 'RESULT..' responses.

Sure it does:

       print "dn: cn=test, dc=example, dc=com\n";
       print "cn: test\n";
       print "objectclass: cnobject\n";
       print "\n";
       print "RESULT\n";
       print "code: 0\n";
       print "info: answered by process $$\n";

And the result at the client:

violino:~/OD/hobj/tests> ../clients/tools/ldapsearch -x -H ldap://:9011 -b 
dc=example,dc=com
# extended LDIF
#
# LDAPv3
# base <dc=example,dc=com> with scope subtree
# filter: (objectclass=*)
# requesting: ALL
#

# test, example.com
dn: cn=test,dc=example,dc=com
cn: test
objectClass: cnobject

# search result
search: 2
result: 0 Success
text:  answered by process 3077

# numResponses: 2
# numEntries: 1

Notice there are no embedded NUL characters. Only newlines.

> I also have less issues when just returning 'CONTINUE\n'.
>
>> Sounds like your problem is a python runtime configuration, not a slapd=
>
>> bug.
>
> Not on Windows and no run-time configuration involved.
>
> Look at the raw string representations I've posted. That string goes dire=
> ctly
> to SocketServer.BaseRequestHandler.request.sendall(response_str).
>
> Can I raise the debug level? Log level trace does not really show the ori=
> ginal
> byte sequence received by the external listener.

Currently there is no debug code for this.

At any rate, the code uses fgets(3) which stops reading at a newline 
character. The fact that your string isn't being parsed correctly implies 
either libc fgets is broken inside your slapd process (pretty unlikely) or 
your socket sender isn't really sending newline characters.

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

Comment 9 Howard Chu 2015-06-30 12:27:37 UTC
hyc@symas.com wrote:
> michael@stroeder.com wrote:

>> Can I raise the debug level? Log level trace does not really show the ori=
>> ginal
>> byte sequence received by the external listener.
>
> Currently there is no debug code for this.

Actually, if you use debug level SHELL you'll get a plaintext dump of the 
received text. If you direct this into a file you can examine it with a hex 
editor.

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

Comment 10 Michael Ströder 2015-06-30 17:39:30 UTC
hyc@symas.com wrote:
> hyc@symas.com wrote:
>> michael@stroeder.com wrote:
> 
>>> Can I raise the debug level? Log level trace does not really show the ori=
>>> ginal
>>> byte sequence received by the external listener.
>>
>> Currently there is no debug code for this.
> 
> Actually, if you use debug level SHELL you'll get a plaintext dump of the 
> received text. If you direct this into a file you can examine it with a hex 
> editor.

I tested this again running as overlay with -d SHELL. See attachment of the
log excerpt as Python string representation read with open(file,'rb') before.

You can find *exactly* the lines from this response string generated by the
external listener:

'RESULT\nmsgid: 1\ncode: 49\ninfo: HOTP value wrong\n\n'

All lines starting with sock search reading line:
(RESULT\n)
(msgid: 1\n)
(code: 49\n)
(info: HOTP value wrong\n)

Excerpt of slapd's log repeated here for better readability in the ITS. Please
note the extra space after "text=" which is not what the external listener
returned.

------------------------------------------------
5592d039 sock search reading line (RESULT
)
5592d039 sock search reading line (msgid: 1
)
5592d039 sock search reading line (code: 49
)
5592d039 sock search reading line (info: HOTP value wrong
)
5592d039 sock search reading line (
)
5592d039 str2result (msgid: 1
code: 49
info: HOTP value wrong

) unknown
5592d039 str2result (
) unknown
5592d039 conn=1000 op=0 RESULT tag=97 err=49 text= HOTP value wrong
------------------------------------------------

Ciao, Michael.
Comment 11 OpenLDAP project 2015-07-02 17:48:08 UTC
fixed in master
fixed in RE25
fixed in RE24
Comment 12 Quanah Gibson-Mount 2015-07-02 17:48:08 UTC
changed notes
changed state Release to Closed