Re: Block in ldap_result call, even after specifying some finite time limit

Hi Anton / Mark,

We have tried NSPR I/O with PRLDAP_OPT_IO_MAX_TIMEOUT set to 50ms and
2000ms (2 seconds). But ldap_result call still blocks in I/O for more
than 2 minutes. Behavior wise, we didn't find any difference from the
default I/O (ldap_init).

To reiterate over our the test scenario... We are using ProxyWorkbench
in between directory server and our application. ProxyWorkbench is
configured such that, it will forward only 1 byte of data in 1 second
of time. The rationale behind doing these experiments is that, our
application should be able to failover to secondary directory server,
if directory server hangs or if there is a delay in network traffic.

Here is the sample that we tried on Windows and the results obtained:

#include "stdio.h"
#include "stdlib.h"
#include <ldap.h>
#include <ldap-standard.h>
#include <ldap_pr.h>
#include <time.h>


int main(int noArgs, char **args)
{
	if(noArgs != 7){
		printf("Usage: search host port bindDN bindPwd base-dn scope");
		exit(1);
	}

	int retCode = -1;

	char *host = args[1];
	char *port = args[2];
	char *bindDN = args[3];
	char *bindPwd = args[4];
	char *base = args[5];
	int scope = atoi(args[6]);

	// Establish connection ....
	LDAP *ld = prldap_init(host, atoi(port), 1);
	// LDAP *ld = ldap_init(host, atoi(port));

	// Set options...
	const unsigned int uiVerLDAP = LDAP_VERSION3;
	retCode = ldap_set_option( ld, LDAP_OPT_PROTOCOL_VERSION, ( void
* )&uiVerLDAP );
	printf("\nSet option status: %x", retCode);
	if(retCode != 0){
		printf("\nSet option failed");
		exit(1);
	}

	retCode = ldap_simple_bind_s(ld, bindDN, bindPwd);
	printf("\nBind status: %x", retCode);
	if(retCode != 0){
		printf("\nbind failed");
		exit(1);
	}

	retCode = prldap_set_session_option( ld, NULL,
PRLDAP_OPT_IO_MAX_TIMEOUT, 50 );
	printf("\nPRLDAP Set option status: %x", retCode);
	if(retCode != 0){
		printf("\nPRLDAP Set option failed");
		exit(1);
	}

	// Search...
	int msgID;
	retCode = ldap_search_ext(ld, base, scope, "(objectclass=*)",
									NULL /* attrs */, 0 /* attrsonly */,
									NULL /* serverctrls */, NULL /* clientctrls */,
									NULL /* timeoutp */, -1 /* sizelimit */,
									&msgID);

	printf("\nAsync search request status: %x; msgID %d", retCode,
msgID);
	if(retCode != 0){
		printf("\nAsynchronous operation request failed.");
		exit(1);
	}

	struct timeval timelimit;
	timelimit.tv_sec = 3;
	timelimit.tv_usec = 0; // micro seconds

	LDAPMessage *result = NULL;
	char *dn = NULL;
	char *AdditionalErrMsg = NULL;

	do
	{
		result = NULL;

		time_t t1 = time(NULL);
		printf("\n T1 is: %ld", t1);

		retCode = ldap_result(ld, msgID,
								0, /* fetch only one entry at a time */
								&timelimit,	&result);

		time_t t2 = time(NULL);
		printf("\n T2 is: %ld", t2);
		printf("\nTime taken in ldap_result: %ld", (t2-t1));

		if(retCode == LDAP_RES_SEARCH_ENTRY)
		{
			LDAPMessage *ldapEntry = ldap_first_entry(ld, result);
			if(ldapEntry != NULL){
				dn = ldap_get_dn(ld, ldapEntry);
				printf("\n%s",dn);
				ldap_memfree(dn);
			}
			else{
				printf("\nERROR: No entry found in result");
			}

			ldap_msgfree(result);
		}
		else if(retCode == LDAP_RES_SEARCH_RESULT){
			int parse_rc = -1;

			parse_rc = ldap_parse_result(ld, result, &retCode,
										NULL, &AdditionalErrMsg,
										NULL, NULL, 0);

			printf("\nFinal Result: %x , %s", retCode, AdditionalErrMsg);

			// Free LDAP message explicitly
			ldap_msgfree(result);
			ldap_memfree(AdditionalErrMsg);
			break;
		}
		else if(retCode == 0){
			printf("\nOperation Timedout at client side");
			break;
		}
		else if(retCode == -1){ // Some error occurred in ldap_result call
			// Get that error code from TLS.
			char *errMsg = NULL;
			retCode = ldap_get_lderrno(ld, NULL, &errMsg);

			printf("\nldap_result returned -1. ERROR: error occurred is %x",
retCode);

			// Abandon the operation
			ldap_abandon_ext(ld, msgID, NULL, NULL);
			break;
		}
	}while(true);

	ldap_unbind(ld);
}

Result - 1 (When the above sample is executed as it is)

Set option status: 0
Bind status: 0
PRLDAP Set option status: 0
Async search request status: 0; msgID 2
 T1 is: 1175260884
 T2 is: 1175261014
Time taken in ldap_result: 130
cn=Directory Administrators, o=company,c=us
 T1 is: 1175261014
 T2 is: 1175261014
Time taken in ldap_result: 0
Operation Timedout at client side

Result - 2 (Changed the PRLDAP_OPT_IO_MAX_TIMEOUT to 2000 ms from 50
ms)

Set option status: 0
Bind status: 0
PRLDAP Set option status: 0
Async search request status: 0; msgID 2
 T1 is: 1175261162
 T2 is: 1175261292
Time taken in ldap_result: 130
cn=Directory Administrators, o=company,c=us
 T1 is: 1175261292
 T2 is: 1175261807
Time taken in ldap_result: 515
cn=Master +àdm+»n,o=Company,c=US
 T1 is: 1175261807^C

Result - 3 (Used default I/O instead of NSPR I/O, by using ldap_init
instead of prldap_init and commented out code snippet related to
PRLDAP_OPT_IO_MAX_TIMEOUT setting)

Set option status: 0
Bind status: 0
Async search request status: 0; msgID 2
 T1 is: 1175260110
 T2 is: 1175260240
Time taken in ldap_result: 130
cn=Directory Administrators, o=company,c=us
 T1 is: 1175260240
 T2 is: 1175260755
Time taken in ldap_result: 515
cn=Master +àdm+»n,o=Company,c=US
 T1 is: 1175260755^C

Please note that, in both the default I/O case and NSPR I/O case,
ldap_result got blocked for more than 2 minutes.
Any comments on this are welcome.

Thanks,
Ramakrishna.