[DIRAPI-55] LDAP API can't be used with log4j default configuration when no 'log4j.properties' is available

• Type: Bug
• Status: Closed
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: 1.0.0-M8
• Fix Version/s: 1.0.0-M9
• Labels: API LDAP LDAPPRotocolDecoder ProtocolDecoderException mina outofmemory
• Environment: jdk1.6, windows 7, Apache Directory Studio Version: 1.5.3.v20100330, apache ldap API, apache-ldap-api-1.0.0-M8-bin
• Assignee: Pierre-Arnaud Marcelot
• Reporter: Aswartha N Rupa
• Created: 24/Oct/11 11:27
• Updated: 20/Jan/12 08:15
• Resolved: 25/Oct/11 10:04

Description

A simple program that performs a search on the sample ldif shipped with apache DS>

public class List {

public static void main(String[] args) throws Exception{
LdapConnection connection = new LdapNetworkConnection( "localhost", 10389 , false);
System.out.println("got connection");

connection.bind( "uid=admin,ou=system", "secret" );
SearchRequest searchRequest = new SearchRequestImpl();
searchRequest.setBase(new Dn("ou=Users,dc=example,dc=com"));
searchRequest.setFilter("(&(sn=)(mail=mplanck))");
searchRequest.setScope(SearchScope.ONELEVEL);
String [] attributes =

{ "cn", "mail", "telephonenumber" }

;
searchRequest.addAttributes(attributes);

SearchCursor cursor = connection.search(searchRequest);

if (cursor.next())

{ Response response = cursor.get(); System.out.println( ((SearchResultEntry)response).getEntry() ); System.out.println( "Trying to close the cursor" ); cursor.close(); }

//SearchResultDone done = cursor.getSearchResultDone();
System.out.println( "Trying to close the connection" );
connection.close();
System.out.println( "Trying to close the cursor done" );
}
}

Its prints the first record and waits for more than 10-15 minutes (after the connection.close() is invoke on main thread) giving out an outofmemory error on protocol decoder. I see two threads [NioProcessor] and [NioSocketConnector] in Running state even after main thread executed its last statement.

With output:
log4j:WARN No appenders could be found for logger (org.apache.directory.ldap.client.api.LdapConnectionConfig).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
got connection
Entry
dn: uid=mplanck,ou=Users,dc=example,dc=com
mail: [e-mail]
cn: Max Planck
telephonenumber: [phone]

Trying to close the cursor
Trying to close the connection
Trying to close the cursor done
org.apache.mina.filter.codec.ProtocolDecoderException: java.lang.OutOfMemoryError: Java heap space (Hexdump: 30 4E 02 01 02 73 49 04 47 6C 64 61 70 3A 2F 2F 61 64 2E 65 78 61 6D 70 6C 65 2E 63 6F 6D 2F 75 69 64 3D 70 64 69 72 61 63 2C 25 32 30 6F 75 3D 55 73 65 72 73 2C 25 32 30 64 63 3D 65 78 61 6D 70 6C 65 2C 64 63 3D 63 6F 6D 3F 3F 62 61 73 65 30 54 02 01 02 73 4F 04 4D 6C 64 61 70 3A 2F 2F 6F 70 65 6E 6C 64 61 70 2E 65 78 61 6D 70 6C 65 2E 63 6F 6D 2F 75 69 64 3D 65 66 65 72 6D 69 2C 25 32 30 6F 75 3D 55 73 65 72 73 2C 25 32 30 64 63 3D 65 78 61 6D 70 6C 65 2C 64 63 3D 63 6F 6D 3F 3F 62 61 73 65 30 56 02 01 02 73 51 04 4F 6C 64 61 70 3A 2F 2F 61 70 61 63 68 65 64 73 2E 65 78 61 6D 70 6C 65 2E 63 6F 6D 2F 75 69 64 3D 72 66 65 79 6E 6D 61 6E 2C 25 32 30 6F 75 3D 55 73 65 72 73 2C 25 32 30 64 63 3D 65 78 61 6D 70 6C 65 2C 64 63 3D 63 6F 6D 3F 3F 62 61 73 65 30 0C 02 01 02 65 07 0A 01 00 04 00 04 00)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:251)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1141)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.OutOfMemoryError: Java heap space
at java.nio.CharBuffer.wrap(CharBuffer.java:350)
at java.lang.StringCoding$StringEncoder.encode(StringCoding.java:238)
at java.lang.StringCoding.encode(StringCoding.java:272)
at java.lang.String.getBytes(String.java:946)
at org.apache.directory.shared.util.Strings.getBytesUtf8(Strings.java:1426)
at org.apache.directory.shared.ldap.model.name.Dn.apply(Dn.java:1222)
at org.apache.directory.shared.ldap.model.name.Dn.<init>(Dn.java:283)
at org.apache.directory.shared.ldap.model.name.Dn.<init>(Dn.java:207)
at org.apache.directory.shared.ldap.model.url.LdapUrl.parseDN(LdapUrl.java:676)
at org.apache.directory.shared.ldap.model.url.LdapUrl.parse(LdapUrl.java:198)
at org.apache.directory.shared.ldap.model.url.LdapUrl.<init>(LdapUrl.java:308)
at org.apache.directory.shared.ldap.codec.actions.searchResultReference.StoreReference.action(StoreReference.java:97)
at org.apache.directory.shared.ldap.codec.actions.searchResultReference.StoreReference.action(StoreReference.java:47)
at org.apache.directory.shared.asn1.ber.grammar.AbstractGrammar.executeAction(AbstractGrammar.java:138)
at org.apache.directory.shared.asn1.ber.Asn1Decoder.treatTLVDoneState(Asn1Decoder.java:599)
at org.apache.directory.shared.asn1.ber.Asn1Decoder.decode(Asn1Decoder.java:735)
at org.apache.directory.shared.ldap.codec.api.LdapDecoder.decode(LdapDecoder.java:157)
at org.apache.directory.shared.ldap.codec.protocol.mina.LdapProtocolDecoder.decode(LdapProtocolDecoder.java:79)
at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCodecFilter.java:241)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
at org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
at org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1141)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)