This discussion is archived
12 Replies Latest reply: May 12, 2011 6:05 AM by 860165 RSS

How to debug com.sun.jndi.ldap

860165 Newbie
Currently Being Moderated
What is the best way to debug com.sun.jndi.ldap classes?

I'm using the sun jndi ldap implementation to authenticate users. It works, but frequently (and seemingly randomly) there is a 15 seconds delay in connecting to the LDAP server. Here are a few things I've tried:

I've added the -Djavax.net.debug system property to get additional output (ssl is being used). I'm not sure what to look for but one interesting thing is that it appears closing the connection causes a "java.net.SocketException: Connection reset by peer: socket write error"

I've connected to the process using JConsole and obtained a stack trace. I'm not sure I'm catching the thread at the right moment, but it looks like it is hanging on com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1096)

I've downloaded source from openjdk.java.net, and attached a debugger, but the source doesn't line up with the binary. Know where I can get source for com.sun.jndi.ldap.* as used in Java 1.6 build 20?

Here is the line that occasionally hangs for 15 seconds:
ctx = new InitialLdapContext(env, null);
  • 1. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    it looks like it is hanging on com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1096)
    Which is deep inside SSL. Nothing to do with LDAP whatsoever.
  • 2. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    Thanks for the reply. As mentioned already, I'm not sure I grabbed the stack trace at the right moment, and even if I did, the fact that the top of the stack was hung on an SSL communication call may not mean much; lower on the stack the LDAP library is invoking the call and could be doing so in a way which causes it to hang.

    I found a post on Stack Overflow (http://stackoverflow.com/questions/1138082/ldap-requests-hanging-for-15-seconds) that suggested my issue could be due to a DNS configuration problem or a Sun bug. I switched from using a hostname to an IP address and the problem persists so I think I can rule DNS out.

    The Sun bug is listed here: http://bugs.sun.com/view_bug.do?bug%5Fid=6870947 . I'm not sure how to confirm this is the issue I have though since I can't get the JDK 6 source code. Interestingly, it looks like JDK 5 is available under a research license (http://java.sun.com/j2se/jrl_download.html). If I'm understanding the bug report correctly it appears the fix will be available in Java 7.

    Oh yeah, it is probably worth mentioning that I've got a PHP application running on the same host that also connects to same LDAP server for authentication and it works without any delay and has been for years. This is making Java look really bad.
  • 3. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    lower on the stack the LDAP library is invoking the call and could be doing so in a way which causes it to hang.
    No, lower on the stack the LDAP library is doing its first piece of I/O on the SSLSocket, i.e. sending the first request, which is causing the SSL handshake, which is hanging for some reason, presumably waiting for a server handshake response, which concerns SSL, not LDAP. LDAP does always send requests: it won't be that.
    I found a post on Stack Overflow
    Not relevant. It is stuck in wait() while doing com.sun.jndi.ldap.Connection.readReply(). You are stuck in the SSL handshake, which would occur before sending the request, which precedes reading the reply. And the DNS lookups have already happened by the time the socket is connected, which it must be to be in the SSL handshake.
    The Sun bug is listed here
    If it's this bug, the question becomes why the LDAP server reset the connection. Which in turn indicates an SSL setup problem such as certificate.
  • 4. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    You seem to be suggesting that the problem is with the SSL certificate. Any suggestions on how to troubleshoot that? I simply obtained the root certificate from my company and installed it in the cacerts.jks keystore of GlassFish:

    keytool -keystore cacerts.jks -import -alias MyCompanyCA -file MyCompanyCA.crt
  • 5. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    Looks OK assuming that is Glassfish's truststore, so I don't think it is the server certificate actually, unless it's of a type that the Java client can't handle - allthough I would expect an SSLException for that. Is the LDAP server using client authentication?
  • 6. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    I'm not exactly sure what you mean by client authentication, but I'm creating a new connection for each authentication request and the credentials of the user are being used to make the connection. In other words I'm not creating a connection first and then checking the user's credentials with bind as is often done with pooled LDAP connections. Here is a snippet of the client code:

    protected void authenticate(String username, String password) throws LoginException {
    String base = LDAP_BASE_DN_PARAM;
    String dn = "CN=" + username + "," + base;
    String url = LDAP_URL_PARAM;
    DirContext ctx = null;

    // Note: This is extremely important since an empty password instructs LDAP to login anonymously.
    if (password == null || password.equals("")) {
    throw new LoginException("Password cannot be empty");
    }

    Properties env = new Properties();
    env.setProperty(Context.INITIAL_CONTEXT_FACTORY, "com.sun.jndi.ldap.LdapCtxFactory");
    env.setProperty(Context.PROVIDER_URL, url);
    env.setProperty(Context.SECURITY_PROTOCOL, "ssl");
    env.setProperty(Context.SECURITY_AUTHENTICATION, "simple");
    env.setProperty(Context.SECURITY_PRINCIPAL, dn);
    env.setProperty(Context.SECURITY_CREDENTIALS, password);

    try {
    long start = System.currentTimeMillis();
    ctx = new InitialLdapContext(env, null);
    long end = System.currentTimeMillis();
    logger.log(Level.FINE, "Elapsed Seconds: {0}", (end - start) / 1000.0f);
    //If here then authentication successful!
    logger.log(Level.FINE, "Authentication successful");

    } catch(NamingException e) {
    LoginException le = new LoginException("Unable to perform login request");
    le.initCause(e);
    throw le;
    } finally {
    if (ctx != null) {
    try {
    ctx.close();
    } catch(NamingException e) {
    LoginException le = new LoginException("Unable to close context");
    le.initCause(e);
    throw le;
    }
    }
    }
    }
  • 7. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    I mean SSL client authentication where the client also has a certificate. But if you were doing that you'd know.

    Your code looks OK, although I too get the connection first then do the LDAP bind via the reconnect() method after changing the principal & credentials. But as I said I don't think the LDAP client code has anything to do with this. What's the LDAP server? And are you sure it's talking SSL? Over the port you're using?

    I would also have a look tom see what other useful SSL & LDAP env properties could be set, e.g. a read timeout.
  • 8. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    I took the connection string that was being used in a PHP application running on Apache on the same host so I think the port and host are good. The PHP application is also using the one connection per authentication strategy with simple authentication over SSL.

    I've tried the com.sun.jndi.ldap.read.timeout and the com.sun.jndi.ldap.connect.timeout parameters, but they don't seem to do anything for me (setting them both to 5 seconds does not prevent 15 second wait).

    I've also tried the debug system property java.security.debug=certpath and can see that the certification path is being resolved successfully, and then afterwards the hang occurs.
  • 9. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    Can you try -Djava.net.debug=ssl,handshake.
  • 10. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    I think you mean javax.net.debug. That is how I noticed the close connection error I mentioned in a previous post (which I'm not sure what to do about). Here is some of the logging:

    INFO: %% No cached client session
    INFO: *** ClientHello, TLSv1
    INFO: RandomCookie:
    INFO: GMT: 1288252248
    INFO: bytes = {
    ...
    INFO: %% Cached client session: [Session-1, TLS_RSA_WITH_AES_128_CBC_SHA]
    INFO: http-thread-pool-8080(4), WRITE: TLSv1 Application Data, length = 80
    INFO: Thread-57, READ: TLSv1 Application Data, length = 48
    ...
    INFO: http-thread-pool-8080(4), WRITE: TLSv1 Application Data, length = 64
    INFO: http-thread-pool-8080(4), called close()
    INFO: http-thread-pool-8080(4), called closeInternal(true)
    INFO: Thread-57, handling exception: java.net.SocketException: Connection reset
    INFO: %% Invalidated: [Session-1, TLS_RSA_WITH_AES_128_CBC_SHA]
    INFO: Thread-57
    INFO: , SEND TLSv1 ALERT:
    INFO: fatal,
    INFO: description = unexpected_message
    INFO: Thread-57, WRITE: TLSv1 Alert, length = 32
    INFO: Thread-57, Exception sending alert: java.net.SocketException: Connection reset by peer: socket write error
    INFO: Thread-57, called closeSocket()
    ...
    INFO: Finalizer, called close()
    INFO: Finalizer, called closeInternal(true)

    The close connection error happens even when the delay does not happen so it might not have anything to do with the delay.
  • 11. Re: How to debug com.sun.jndi.ldap
    EJP Guru
    Currently Being Moderated
    I'd like to see what's in the elided dotted sections. The main issue here is the premature close. Can you enable any logging at the LDAP server side?
  • 12. Re: How to debug com.sun.jndi.ldap
    860165 Newbie
    Currently Being Moderated
    The part of the logging that is in elipses includes info about all certificates being loaded such as:

    Subject: CN=thawte Primary Root CA, OU="(c) 2006 thawte, Inc. - For authorized use only", OU=Certifi...
    Issuer: CN=thawte Primary Root CA, OU="(c) 2006 thawte, Inc. - For authorized use only", OU=Certifi...
    Algorithm: RSA; Serial number: 0x344...
    Valid from Thu Nov 16 19:00:00 EST 2006 until Wed Jul 16 19:59:59 EDT 2036
    adding as trusted cert...

    Also the bytes that are being exchanged are dumped to the log such as:
    142
    126
    236
    224
    222
    253
    ...

    The LDAP server is maintained by a department in our company that I'm not a member of so getting them to participate in the debugging effort is a little tricky, especially since they have it working with numerous other (non-Java) applications. Their first reaction is that the problem is with Java (and at this point I'm starting to agree since even I have it working on the exact same server with PHP). In the meantime I've created a Java LoginModule that uses IMAP instead of LDAP and it appears to be working great so I guess I'm abandoning Java LDAP authentication.

    Note: If I use an LDAP LoginModule that uses connection pooling (the one that comes with GlassFish for example) then I don't have any delays. I assume this is because the connections are created before the user tries to authenticate and then are pooled so as to not incur the creation costs again. I'm not in a position to use connection pooling however because our LDAP server is not configured for anonymous binds and I don't have an account just for making connections (I used my personal account when experimenting, but what I need to do in production is essentially auth-only mode as found in the JAAS LDAPLoginModule).

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points