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

JLDAP: NullPointerException thrown in com.novell.ldap.Message::putReply() causing application to hang

Hi,

This is related to the hang when using the JLDAP libraries. It appeared
there was no other reproducible scenario for anyone to debug with so I
figured I'd try debugging it on my own.

On debugging with the latest JLDAP code (Tag = HEAD) I found a nullpointer
exception thrown in the following code (below) of
com.novell.ldap.Message(the line that has an exception is identified
using "<<<..."). Also, before
this happened, based on the debugger, threads were being created and
destroyed almost as though it was going to be an infinite loop. **Then
suddenly this NullPointerException exception occurs and the application
hangs**. Call-stack is included at the bottom, and so are the last few trace
messages before the crash. (FYI, I'm using JLDAP to connect to an OpenLDAP
server that is running on windows).

/**
* Puts a reply on the reply queue
*
* @param message the RfcLDAPMessage to put on the reply queue.
*/
/* package */
void putReply( RfcLDAPMessage message)
{
if( ! acceptReplies) {
if( Debug.LDAP_DEBUG ) {
Debug.trace( Debug.messages, name +
"not accepting replies, discarding reply");
}
return;
}
replies.addElement( message);
message.setRequestingMessage( msg); // Save request message info
switch( message.getType()) {
case LDAPMessage.SEARCH_RESPONSE:
case LDAPMessage.SEARCH_RESULT _REFERENCE:
case LDAPMessage.INTERMEDIATE_RESPONSE:
// SearchResultEntry or SearchResultReference
if( Debug.LDAP_DEBUG) {
Debug.trace( Debug.messages, name +
"Reply Queued (" + replies.size() + " in queue)");
}
break;


default:
// All Responses with a result code
int res;
if( Debug.LDAP_DEBUG) {
res = ((RfcResponse)message.getResponse()).getResultCode().intValue();
Debug.trace( Debug.messages, name +
"Queued LDAPResult (" + replies.size() +
" in queue), message complete stopping timer, status " + res);
}
stopTimer();
// Accept no more results for this message
// Leave on connection queue so we can abandon if necessary
acceptReplies = false;
complete = true;
if( bindprops != null) {
if( Debug.LDAP_DEBUG) {
Debug.trace( Debug.messages, name + "Bind properties found");
}
res = ((RfcResponse)message.getResponse()).getResultCode().intValue();
if(res == LDAPException.SASL_BIND_IN_PROGRESS) {
if( Debug.LDAP_DEBUG) {
Debug.trace( Debug.messages, name + "Sasl Bind in-progress status");
}
} else {
// We either have success or failure on the bind
if(res == LDAPException.SUCCESS) {
// Set bind properties into connection object
conn.setBindProperties(bindprops);
if( Debug.LDAP_DEBUG) {
Debug.trace( Debug.messages, name + "Bind status success");
}
} else {
if( Debug.LDAP_DEBUG) {
Debug.trace( Debug.messages, name + "Bind status " + res);
}
}
// If not a sasl bind in-progress, release the bind
// semaphore and wake up all waiting threads
int id;
if( conn.isBindSemIdClear()) { <<<<<<<<<<<<<<<<<<<< This is where a
NullPointerException occurs.
// Semaphore id for normal operations
id = msgId;
} else {
// Semaphore id for sasl bind
id = conn.getBindSemId();
conn.clearBindSemId();
}
conn.freeWriteSemaphore(id);
}
}
}
// wake up waiting threads
sleepersAwake();
return;
}

I'm not familiar with the JLDAP code (just started playing with it) so if
you need further information do let me know. I don't know what might be
causing the 'conn' object to be null, but since it's a runtime exception,
I'm guessing something is not working right within the JLDAP library.

Any ideas?

Thanks,
Safdar

 Call-stack in hung state:
-------------------------
org.eclipse.jdt.internal.junit.runner.RemoteTestRunner at
localhost:3774 (Suspended)
	System Thread [Finalizer] (Suspended)
		Object.wait(long) line: not available [native method]
		ReferenceQueue.remove(long) line: not available
		ReferenceQueue.remove() line: not available
		Finalizer$FinalizerThread.run() line: not available
	System Thread [Reference Handler] (Suspended)
		Object.wait(long) line: not available [native method]
		Reference$Lock(Object).wait() line: not available
		Reference$ReferenceHandler.run() line: not available
	Thread [main] (Suspended)
		Object.wait(long) line: not available [native method]
		Object.wait() line: not available
		Connection.acquireWriteSemaphore(int) line: 240
		Connection.writeMessage(LDAPMessage) line: 679
		Connection.writeMessage(Message) line: 648
		Message.sendMessage() line: 101
		MessageAgent.sendMessage(Connection, LDAPMessage, int,
LDAPMessageQueue, BindProperties) line: 286
		LDAPConnection.search(String, int, String, String[], boolean,
LDAPSearchQueue, LDAPSearchConstraints) line: 3468
		LDAPConnection.search(String, int, String, String[], boolean,
LDAPSearchConstraints) line: 3349
		LDAPConnection.search(String, int, String, String[], boolean) line: 3300
		OpenLDAPUserRepositoryImpl.getUser(long) line: 596
		ApplicationUserManagerImpl.getPrimaryAccessGroupForUser(long) line: 1046
		TestApplicationUserManagerWithLocalAuth(BaseTestApplicationUserManager).testAllMembershipOperations()
line: 556
		NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
available [native method]
		NativeMethodAccessorImpl.invoke(Object, Object[]) line: not available
		DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: not available
		Method.invoke(Object, Object[]) line: not available
		TestApplicationUserManagerWithLocalAuth(TestCase).runTest() line: 154
		TestApplicationUserManagerWithLocalAuth(TestCase).runBare() line: 127
		TestResult$1.protect() line: 106
		TestResult.runProtected(Test, Protectable) line: 124
		TestResult.run(TestCase) line: 109
		TestApplicationUserManagerWithLocalAuth(TestCase).run(TestResult) line: 118
		TestSuite.runTest(Test, TestResult) line: 208
		TestSuite.run(TestResult) line: 203
		RemoteTestRunner.runTests(String[], String) line: 421
		RemoteTestRunner.run() line: 305
		RemoteTestRunner.main(String[]) line: 186
	System Thread [Signal Dispatcher] (Suspended)
	Thread [ReaderThread] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		StreamDecoder$CharsetSD.readBytes() line: not available
		StreamDecoder$CharsetSD.implRead(char[], int, int) line: not available
		StreamDecoder$CharsetSD(StreamDecoder).read(char[], int, int) line:
not available
		InputStreamReader.read(char[], int, int) line: not available
		BufferedReader.fill() line: not available
		BufferedReader.readLine(boolean) line: not available
		BufferedReader.readLine() line: not available
		RemoteTestRunner$ReaderThread.run() line: 139
	Thread [Thread-0] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180
		Thread.run() line: not available
	Thread [Thread-15] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180
		Thread.run() line: not available
	Thread [Thread-39] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180
		Thread.run() line: not available
	Thread [Thread-57] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180
		Thread.run() line: not available
	Thread [Thread-255] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180
		Thread.run() line: not available
	Thread [Thread-295] (Suspended)
		SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
		SocketInputStream.read(byte[], int, int) line: not available
		SocketInputStream.read() line: not available
		ASN1Identifier.<init>(InputStream) line: 129
		Connection$ReaderThread.run() line: 1180

LOGS (last several hundred lines):
----------------------------------
17:02:09.727 traceMessages: Connection(2066):  connect: setup complete
17:02:09.727 traceAPIRequests: LDAPConnection(1941):
bind("cn=Manager,dc=XYZ,dc=com")
17:02:09.727 traceAPIRequests: Creating [UNIVERSAL 16] SEQUENCE: {
[UNIVERSAL 2] INTEGER: 7041, [APPLICATION 0] SEQUENCE: { [UNIVERSAL 2]
INTEGER: 3, [UNIVERSAL 4] OCTET STRING: cn=Manager,dc=XYZ,dc=com,
[CONTEXT 0] OCTET STRING: 123blue! } }
17:02:09.727 traceBindSemaphore: Connection(2066): Acquired Socket
Write Semaphore(7041) count 1
17:02:09.727 traceMessages: MessageAgent(4230): Created
17:02:09.727 traceMessages: LDAPResponseQueue(4230): Created
17:02:09.727 traceMessages: Message(7041):  Created with mslimit 0
17:02:09.727 traceMessages: MessageAgent(4230): sendMessage: Added new
Message(7041)
17:02:09.727 traceMessages: MessageAgent(4230): Queue Status
17:02:09.727 traceMessages: MessageAgent(4230): 	0.: Message(7041)
17:02:09.727 traceMessages: Message(7041): Sending request to Connection(2066):
17:02:09.727 traceMessages: Connection(2066): Writing Message(7041)
17:02:09.727 traceRawInput: Connection(2066): RawWrite: [UNIVERSAL 16]
SEQUENCE: { [UNIVERSAL 2] INTEGER: 7041, [APPLICATION 0] SEQUENCE: {
[UNIVERSAL 2] INTEGER: 3, [UNIVERSAL 4] OCTET STRING:
cn=Manager,dc=XYZ,dc=com, [CONTEXT 0] OCTET STRING: 123blue! } }
17:02:09.727 traceBindSemaphore: Connection(2066): Acquired Socket
Write Semaphore(7041) count 2
17:02:09.727 traceMessages: RfcLDAPMessage: input message w/tag 1
17:02:09.727 traceRawInput: Connection(2066): RawRead: [UNIVERSAL 16]
SEQUENCE: { [UNIVERSAL 2] INTEGER: 7041, [APPLICATION 1] SEQUENCE: {
[UNIVERSAL 10] ENUMERATED: 0, [UNIVERSAL 4] OCTET STRING: , [UNIVERSAL
4] OCTET STRING:  } }
17:02:09.727 traceMessages: Connection(2066): reader: queue response
to message(7041)
17:02:09.727 traceMessages: Message(7041): Queued LDAPResult (1 in
queue), message complete stopping timer, status 0
17:02:09.727 traceMessages: Message(7041): Bind properties found
17:02:09.727 traceBindSemaphore: Connection(2066): Free'd Socket Write
Semaphore(7041) count 1
17:02:09.743 traceAPIRequests: LDAPResponseQueue(4230): getResponse(null)
17:02:09.743 traceMessages: MessageAgent(4230): getLDAPMessage(null),
1 messages active
17:02:09.743 traceAPIRequests: LDAPConnection(1938): finalize()
17:02:09.743 traceMessages: Connection(2063): destroyClone(false)
17:02:09.743 traceMessages: Message(7035): finalize
17:02:09.743 traceMessages: Message(7035): cleanup
17:02:09.743 traceMessages: Connection(2064): Removing Message(7035) - not found
17:02:09.743 traceMessages: Message(7035): cleanup: remove 1 replies
17:02:09.743 traceAPIRequests: LDAPConnection(1940): finalize()
17:02:09.743 traceMessages: Connection(2065): destroyClone(false)
17:02:09.743 traceMessages: Message(7034): finalize
17:02:09.743 traceMessages: Message(7034): cleanup
17:02:09.743 traceMessages: Connection(2065): finalize: shutdown connection
17:02:09.743 traceMessages: Connection(2065): shutdown: already
shutdown - Finalize
17:02:09.743 traceMessages: Connection(2064): finalize: shutdown connection
17:02:09.743 traceMessages: Connection(2064): shutdown: already
shutdown - Finalize
17:02:09.743 traceMessages: Message(7038): finalize
17:02:09.743 traceMessages: Message(7038): cleanup
17:02:09.743 traceAPIRequests: LDAPConnection(1939): finalize()
17:02:09.743 traceMessages: Connection(2064): destroyClone(false)
17:02:09.743 traceMessages: Message(7039): finalize
17:02:09.743 traceMessages: Message(7039): cleanup
17:02:09.743 traceMessages: Message(7031): finalize
17:02:09.743 traceMessages: Message(7031): cleanup
17:02:09.743 traceMessages: Connection(2063): Removing Message(7031) - not found
17:02:09.743 traceMessages: Message(7031): cleanup: remove 1 replies
17:02:09.743 traceMessages: Connection(2063): finalize: shutdown connection
17:02:09.743 traceMessages: Connection(2063): shutdown: already
shutdown - Finalize
17:02:09.743 traceMessages: MessageAgent(4230): getLDAPMessage: Look
for any reply, 1 messages active
17:02:09.743 traceMessages: Message(7041): Got reply from queue(0
remaining in queue)
17:02:09.743 traceMessages: Connection(2066): Removed Message(7041)
17:02:09.743 traceMessages: MessageAgent(4230): getLDAPMessage:
cleanup Message(7041)
17:02:09.743 traceMessages: Message(7041): Abandon request,
complete=true, bind=true, informUser=false, waitForReply=true
17:02:09.743 traceMessages: Message(7041): Sleepers Awake, MessageAgent(4230):
17:02:09.743 traceMessages: Message(7041): cleanup
17:02:09.743 traceMessages: Connection(2066): Removing Message(7041) - not found
17:02:09.743 traceMessages: MessageAgent(4230): getLDAPMessage: Return
response to Message(7041)
17:02:09.743 traceMessages: MessageAgent(4230): Queue Status
17:02:09.743 traceMessages: MessageAgent(4230): 	No messages queued
17:02:09.743 traceMessages: LDAPResponse: message(7041) result code 0
17:02:09.743 traceAPIRequests: LDAPConnection(1941): search("ou=User
Management,dc=XYZData,dc=XYZ,dc=com",2,"(&(objectClass=ApplicationUser)(XYZID=1410))")
17:02:09.743 traceAPIRequests: Creating LDAPSearchRequest(7042):
[UNIVERSAL 16] SEQUENCE: { [UNIVERSAL 2] INTEGER: 7042, [APPLICATION
3] SEQUENCE: { [UNIVERSAL 4] OCTET STRING: ou=User
Management,dc=XYZData,dc=XYZ,dc=com, [UNIVERSAL 10] ENUMERATED: 2,
[UNIVERSAL 10] ENUMERATED: 0, [UNIVERSAL 2] INTEGER: 1000, [UNIVERSAL
2] INTEGER: 0, [UNIVERSAL 1] BOOLEAN: false, [CONTEXT 0] SET OF: {
[CONTEXT 3] SEQUENCE: { [UNIVERSAL 4] OCTET STRING: objectClass,
[UNIVERSAL 4] OCTET STRING: ApplicationUser }, [CONTEXT 3] SEQUENCE: {
[UNIVERSAL 4] OCTET STRING: XYZID, [UNIVERSAL 4] OCTET STRING: 1410 }
}, [UNIVERSAL 16] SEQUENCE OF: {  } } }
17:02:09.743 traceMessages: MessageAgent(4231): Created
17:02:09.743 traceMessages: LDAPSearchQueue(4231): Created
17:02:09.743 traceMessages: Message(7042):  Created with mslimit 0
17:02:09.743 traceMessages: MessageAgent(4231): sendMessage: Added new
Message(7042)
17:02:09.743 traceMessages: MessageAgent(4231): Queue Status
17:02:09.743 traceMessages: MessageAgent(4231): 	0.: Message(7042)
17:02:09.743 traceMessages: Message(7042): Sending request to Connection(2066):
17:02:09.743 traceMessages: Connection(2066): Writing Message(7042)
17:02:09.743 traceRawInput: Connection(2066): RawWrite: [UNIVERSAL 16]
SEQUENCE: { [UNIVERSAL 2] INTEGER: 7042, [APPLICATION 3] SEQUENCE: {
[UNIVERSAL 4] OCTET STRING: ou=User
Management,dc=XYZData,dc=XYZ,dc=com, [UNIVERSAL 10] ENUMERATED: 2,
[UNIVERSAL 10] ENUMERATED: 0, [UNIVERSAL 2] INTEGER: 1000, [UNIVERSAL
2] INTEGER: 0, [UNIVERSAL 1] BOOLEAN: false, [CONTEXT 0] SET OF: {
[CONTEXT 3] SEQUENCE: { [UNIVERSAL 4] OCTET STRING: objectClass,
[UNIVERSAL 4] OCTET STRING: ApplicationUser }, [CONTEXT 3] SEQUENCE: {
[UNIVERSAL 4] OCTET STRING: XYZID, [UNIVERSAL 4] OCTET STRING: 1410 }
}, [UNIVERSAL 16] SEQUENCE OF: {  } } }
17:02:09.727 traceMessages: Message(7041): Bind status success
17:02:09.743 traceMessages: Connection(2066): reader: connection shutdown
17:02:09.743 traceTLS: reader: Stopping thread, retaining the connection
java.lang.NullPointerException
	at com.novell.ldap.Message.putReply(Message.java:340)
	at com.novell.ldap.Connection$ReaderThread.run(Connection.java:1214)
	at java.lang.Thread.run(Unknown Source)
		Thread.run() line: not available