ICE error: "ldap_simple_bind timed out"

I am a developer of an automatic network monitoring system called 
SysOrb.  One of our customers would like to use our product to among 
other things monitor their eDirectory server through LDAP.  To do that 
he is using the ICE command line tool.  I am not familiar with ICE or 
eDirectory at all, but our customer asserts that the following command 
would be good for checking if their eDirectory server is working:

ice -S LDAP -s raiki06.xxxx.xxxx.de -p 636 -d cn=admin,o=xxxx -w 
'password' -a cn -b cn=admin,o=xxxx -c sub -D LDIF -f /dev/null

I have no idea what this command does, other than it contacts a LDAP 
server in some way, and if its shell exit code is not zero, then there 
is probably something wrong with the eDirectory server.

This is all very fine, out customer can run this from the command line 
and get a zero exit code.  However, when he makes our monitoring agent 
program execute the exact same command, it behaves differently.  This is 
the typical output when run from our agent:

Novell Import Convert Export utility for Novell eDirectory
version: 10552.51
Copyright 2000 Novell, Inc.  All rights reserved.  Patent Pending.
Source Handler: ICE LDAP handler for Novell eDirectory (version: 10552.51 )
Destination Handler: ICE LDIF handler for Novell eDirectory (version: 
10552.51 )
ldap_simple_bind timed out - problem communicating with the server
You may type 'ice' to see the command line help.

I do not believe this is really a timeout, as all of the above is output 
within less than one second.

To get a better idea of what is going on, I have had our customer run 
ice though strace, both in a case when it worked, and in a case when it 
displayed the "timeout" problem.  This is the interesting part, where

the traces begin to differ:

 From a run that worked:

write(3,
"\27\3\0\0\30\5\0\203\371\272\205U\4\223\247\314\244]Y\202"..., 
90) = 90
gettimeofday({1155817537, 102207}, NULL) = 0
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 1200000) = 1
read(3, "\27\3\0\0(", 5)                = 5

 From a run with "timeout" problem:

write(0,
"\27\3\0\0\30\23\344\242\327\313t\370T}M\207\250|\373h\264"..., 
90) = 90
gettimeofday({1155882463, 644493}, NULL) = 0
write(2, "ldap_simple_bind timed out - pro"..., 67) = 67

As you can see, in the latter case the ice program does not even call 
poll() to ask the operating system if any data has arrived.  It seems it 
sends a 90 bytes request, and then immediately thereafter informs the 
user of the "timeout".

Does anyone out there have an idea of what can cause the ice program to 
do that?

Our customer has also tried using the ldapsearch program instead of ice. 
  That does not work either.  I have not seen traces, but it seems to be 
the same problem, and it only appears if using SSL.

My guess is that this has to do with an SSL library common between ice 
and ldapsearch.  If anyone here knows about the inner workings of such a 
library, or has any other suggestions, then I would be more than happy 
to know about it.

If you need to see more of the traces, then please do not hesitate to ask.

Regards
Jes Klinke

I don't know much about your product, but what platform is this
test being run on? If its Linux/Unix when you execute the command
does it have the rights to open a port below 1024 as it needs to
open the secure LDAP port on 636.

Roger


"Jes Bodi Klinke" <jbk@evalesco.com> wrote in message
news:ekZGg.1345$%n2.634@prv-forum2.provo.novell.com...
> I am a developer of an automatic network monitoring system called
> SysOrb.  One of our customers would like to use our product to among
> other things monitor their eDirectory server through LDAP.  To do that
> he is using the ICE command line tool.  I am not familiar with ICE or
> eDirectory at all, but our customer asserts that the following command
> would be good for checking if their eDirectory server is working:
>
> ice -S LDAP -s raiki06.xxxx.xxxx.de -p 636 -d cn=admin,o=xxxx -w
> 'password' -a cn -b cn=admin,o=xxxx -c sub -D LDIF -f /dev/null
>
> I have no idea what this command does, other than it contacts a LDAP
> server in some way, and if its shell exit code is not zero, then there
> is probably something wrong with the eDirectory server.
>
> This is all very fine, out customer can run this from the command line
> and get a zero exit code.  However, when he makes our monitoring agent
> program execute the exact same command, it behaves differently.  This is
> the typical output when run from our agent:
>
> Novell Import Convert Export utility for Novell eDirectory
> version: 10552.51
> Copyright 2000 Novell, Inc.  All rights reserved.  Patent Pending.
> Source Handler: ICE LDAP handler for Novell eDirectory (version: 10552.51
)
> Destination Handler: ICE LDIF handler for Novell eDirectory (version:
> 10552.51 )
> ldap_simple_bind timed out - problem communicating with the server
> You may type 'ice' to see the command line help.
>
> I do not believe this is really a timeout, as all of the above is output
> within less than one second.
>
> To get a better idea of what is going on, I have had our customer run
> ice though strace, both in a case when it worked, and in a case when it
> displayed the "timeout" problem.  This is the interesting part,
where
> the traces begin to differ:
>
>  From a run that worked:
>
> write(3,
"\27\3\0\0\30\5\0\203\371\272\205U\4\223\247\314\244]Y\202"...,
> 90) = 90
> gettimeofday({1155817537, 102207}, NULL) = 0
> poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 1200000) = 1
> read(3, "\27\3\0\0(", 5)                = 5
>
>  From a run with "timeout" problem:
>
> write(0,
"\27\3\0\0\30\23\344\242\327\313t\370T}M\207\250|\373h\264"...,
> 90) = 90
> gettimeofday({1155882463, 644493}, NULL) = 0
> write(2, "ldap_simple_bind timed out - pro"..., 67) = 67
>
> As you can see, in the latter case the ice program does not even call
> poll() to ask the operating system if any data has arrived.  It seems it
> sends a 90 bytes request, and then immediately thereafter informs the
> user of the "timeout".
>
> Does anyone out there have an idea of what can cause the ice program to
> do that?
>
> Our customer has also tried using the ldapsearch program instead of ice.
>   That does not work either.  I have not seen traces, but it seems to be
> the same problem, and it only appears if using SSL.
>
> My guess is that this has to do with an SSL library common between ice
> and ldapsearch.  If anyone here knows about the inner workings of such a
> library, or has any other suggestions, then I would be more than happy
> to know about it.
>
> If you need to see more of the traces, then please do not hesitate to ask.
>
> Regards
> Jes Klinke
> Evalesco Systems

Hello Roger

I am sorry I forgot to mention, that the ice command was being run on Linux.

The program is being run a root in both cases, but actually as far as I 
know, you do not need root privileges just to connect to a port below 
1024, (only if you want to listen on such a port, like e.g. the LDAP 
server.)

I have found out, what was the difference between running the script on 
the command line, and running it through our monitoring software.  Our 
software had closed the file descriptor zero (standard input), meaning 
that when ice opens a socket, that socket will be given file descriptor 
zero.  (You can see that on the first strace, ice uses file descriptor 
3, whereas on the second strace, it uses file descriptor 0.)

Nothing is really wrong with using file descriptor zero for other things 
besides standard input.  (And it works if you use ldapsearch without 
SSL.)  But it appears that the Novell SSL library does not work 
properly, when the socket has descriptor zero.

We will modify our monitoring software to open /dev/null as file 
descriptor zero (standard input) before spawning the ice command, that 
should overcome the problem.

Regards
Jes Klinke
Evalesco Systems

Roger wrote:
> I don't know much about your product, but what platform is this
> test being run on? If its Linux/Unix when you execute the command
> does it have the rights to open a port below 1024 as it needs to
> open the secure LDAP port on 636.
> 
> Roger
> 
> 
> "Jes Bodi Klinke" <jbk@evalesco.com> wrote in message
news:ekZGg.1345$%n2.634@prv-forum2.provo.novell.com...
>> I am a developer of an automatic network monitoring system called
>> SysOrb.  One of our customers would like to use our product to among
>> other things monitor their eDirectory server through LDAP.  To do that
>> he is using the ICE command line tool.  I am not familiar with ICE or
>> eDirectory at all, but our customer asserts that the following command
>> would be good for checking if their eDirectory server is working:
>>
>> ice -S LDAP -s raiki06.xxxx.xxxx.de -p 636 -d cn=admin,o=xxxx -w
>> 'password' -a cn -b cn=admin,o=xxxx -c sub -D LDIF -f /dev/null
>>
>> I have no idea what this command does, other than it contacts a LDAP
>> server in some way, and if its shell exit code is not zero, then there
>> is probably something wrong with the eDirectory server.
>>
>> This is all very fine, out customer can run this from the command line
>> and get a zero exit code.  However, when he makes our monitoring agent
>> program execute the exact same command, it behaves differently.  This
is
>> the typical output when run from our agent:
>>
>> Novell Import Convert Export utility for Novell eDirectory
>> version: 10552.51
>> Copyright 2000 Novell, Inc.  All rights reserved.  Patent Pending.
>> Source Handler: ICE LDAP handler for Novell eDirectory (version:
10552.51 )
>> Destination Handler: ICE LDIF handler for Novell eDirectory (version:
>> 10552.51 )
>> ldap_simple_bind timed out - problem communicating with the server
>> You may type 'ice' to see the command line help.
>>
>> I do not believe this is really a timeout, as all of the above is
output
>> within less than one second.
>>
>> To get a better idea of what is going on, I have had our customer run
>> ice though strace, both in a case when it worked, and in a case when
it
>> displayed the "timeout" problem.  This is the interesting
part, where
>> the traces begin to differ:
>>
>>  From a run that worked:
>>
>> write(3,
"\27\3\0\0\30\5\0\203\371\272\205U\4\223\247\314\244]Y\202"...,
>> 90) = 90
>> gettimeofday({1155817537, 102207}, NULL) = 0
>> poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 1200000) = 1
>> read(3, "\27\3\0\0(", 5)                = 5
>>
>>  From a run with "timeout" problem:
>>
>> write(0,
"\27\3\0\0\30\23\344\242\327\313t\370T}M\207\250|\373h\264"...,
>> 90) = 90
>> gettimeofday({1155882463, 644493}, NULL) = 0
>> write(2, "ldap_simple_bind timed out - pro"..., 67) = 67
>>
>> As you can see, in the latter case the ice program does not even call
>> poll() to ask the operating system if any data has arrived.  It seems
it
>> sends a 90 bytes request, and then immediately thereafter informs the
>> user of the "timeout".
>>
>> Does anyone out there have an idea of what can cause the ice program
to
>> do that?
>>
>> Our customer has also tried using the ldapsearch program instead of
ice.
>>   That does not work either.  I have not seen traces, but it seems to
be
>> the same problem, and it only appears if using SSL.
>>
>> My guess is that this has to do with an SSL library common between ice
>> and ldapsearch.  If anyone here knows about the inner workings of such
a
>> library, or has any other suggestions, then I would be more than happy
>> to know about it.
>>
>> If you need to see more of the traces, then please do not hesitate to
ask.
>>
>> Regards
>> Jes Klinke
>> Evalesco Systems
>