[Date Prev][Date Next]
[Chronological]
[Thread]
[Top]
Re: JLDAP: NullPointerException thrown in com.novell.ldap.Message::putReply() causing application to hang
To try to temporarily fix the problem in my earlier email, I proceeded to
add a null-check in the same putReply() metho, as shown below:
default:
// All Responses with a result code
int res;
if( Debug.LDAP_DEBUG) {
res = ((RfcResponse)message.getRespon
>
> se()).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 ( conn!=null && bindprops != null) { <<<<<<<<<<<<<<<<<<<<<< ADDED
> NULL-CHECK FOR 'CONN' HERE 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()) {
> // 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;
> }
>
However, now I get the following exception during one of the bind() calls.
For some reason, it appears that the "conn" member variable and the "myOut"
variables are not being initialized as necessary. i'm guessing this is
likely to be the case for many other member variables. any ideas why this
might be happening? as you can see in teh call-stack below, this particular
excpetion is occuring in the bind() on the LDAPconnection object.
com.bluejungle.destiny.containe
r.shared.applicationusers.core.AccessGroupDeletionFailedException:
com.bluejungle.destiny.container.shared.applicationusers.core.UserManagementAccessException:
com.bluejungle.destiny.container.shared.applicationusers.repository.ApplicationUserRepositoryAccessException:
LDAPException: I/O Exception on host localhost, port 389 (91) Connect Error
Caused by: LDAPException: I/O Exception on host localhost, port 389 (91)
Connect Error
java.io.IOException: Output stream not initialized
at com.novell.ldap.Connection.writeMessage(Connection.java:712)
at com.novell.ldap.Connection.writeMessage(Connection.java:648)
at com.novell.ldap.Message.sendMessage(Message.java:101)
at com.novell.ldap.MessageAgent.sendMessage(MessageAgent.java:286)
at com.novell.ldap.LDAPConnection.sendRequestToServer(LDAPConnection.java
:3680)
at com.novell.ldap.LDAPConnection.bind(LDAPConnection.java:1481)
at com.novell.ldap.LDAPConnection.bind(LDAPConnection.java:1349)
at com.novell.ldap.LDAPConnection.bind(LDAPConnection.java:1310)
thanks,
Safdar
On 10/24/05, Safdar Kureishy <safdar.kureishy@gmail.com> wrote:
>
> 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
>
>
>