Configured for Active Directory, but

Hello,

Currently using OpenFire 4.0.2/Windows 7

Configured Active Directory, and it works OK. I am able to log-in through Admin console.

However, the problem is that…sometimes…well,…randomly…

I see Connection timed out exception…

org.jivesoftware.openfire.auth.UnauthorizedException: javax.naming.CommunicationException: MyADServer.local:389 [Root exception is java.net.ConnectException: Connection timed out: connect]

at org.jivesoftware.openfire.ldap.LdapAuthProvider.authenticate(LdapAuthProvider.j ava:137)

Caused by: javax.naming.CommunicationException: MyADServer.local:389[Root exception is java.net.ConnectException: Connection timed out: connect]

at com.sun.jndi.ldap.Connection.(Unknown Source)

Caused by: java.net.ConnectException: Connection timed out: connect

Once I see this exception, then…after a while, I am able to login again successfully…then…at some point, I see that exception again.

I thought this might be ldap.connectionTimeout issue…however, it wasn’t. Regardless of how I set the Timeout value, the same behavior persists…

So…my guess would be somehow LdapAuthProvider connection leaks internally??

Any idea?

Thanks,

I’ve seen this a time or two, and it was either a java bug or network issue. are you able to consistently reproduce the issue? or does it seem random? are you running openfire or your DC on vmware? do you experience any DNS issue during the same time?

I believe it is more likely a bug…

Hum…it happens randomly…No vmware…No DNS issue during that period… Since it happens randomly, not sure which one triggers this issue, but looks like…this issue happens at some point…

Try turn debug logging on for Openfire (there is an article regarding how to do that) and check the output. There might be some (not only 1 exception) - usualy root cause is the very first one, others are just happened because of this #1.

It looks like something LDAP-related running in background which terminating occasionally. And yes, I’d like to ask you the same as speedy asked: any clear and known sequence of actions to reproduce that? Probably you’re clicking same buttonos/URLs? Maybe amount of time between successful login and abnormal stop? We need any known dependencies to localize the source of the problem. Debug log will be a good starting point.

again, there is no any clear known sequence to produce this issue…it just happens randomly at some point…

Btw, I created LdapAuthProvider test class for unit testing… but i cant figure out how to pass connection information manually via code for testing. Do you know by any chance how?

Thanks

Unfortunately I can’t be helpful here with classes etc., I’m an administrator but not programmer. Did you have any chance to check debug log? Anything interesting here? I f you could share a piece of this log (with some events happened just before problem), we could try to check it together.

Hello,

OK, here is the log when AD authentication was successful.

016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Trying to find a user’s DN based on their username. sAMAccountName: jay, Base DN: OU=“Blah1”,DC=“Blah2”,DC=“Blah3”,DC=“Blah4”…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Creating a DirContext in LdapManager.getContext()…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Warning: Using unencrypted connection to LDAP service!

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Created hashtable with context values, attempting to create context…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: … context created successfully, returning.

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Starting LDAP search…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: … search finished

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: In LdapManager.checkAuthentication(userDN, password), userDN is: BlahBlah…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Warning: Using unencrypted connection to LDAP service!

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Created context values, attempting to create context…

2016.05.05 10:37:17 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: … context created successfully, returning.

2016.05.05 10:37:17 org.jivesoftware.util.cert.SANCertificateIdentityMapping - Parsing otherName for subject alternative names: x.x.x.x.x.x

2016.05.05 10:37:17 org.jivesoftware.util.cert.SANCertificateIdentityMapping - … processing DERTaggedObject: [0][0]MyADServer

2016.05.05 10:37:17 org.jivesoftware.util.CertificateManager - CertificateManager: Subject Alternative Name Mapping returned [MyADServer]

Here is the log when AD authentication was unsuccessful for whatever some reason.

2016.05.05 10:44:32 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Trying to find a user’s DN based on their username. sAMAccountName: jay, Base DN: OU=“Blah1”,DC=“Blah2”,DC=“Blah3”,DC=“Blah4”…

2016.05.05 10:44:32 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Creating a DirContext in LdapManager.getContext()…

2016.05.05 10:44:32 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Warning: Using unencrypted connection to LDAP service!

2016.05.05 10:44:32 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Created hashtable with context values, attempting to create context…

2016.05.05 10:44:53 org.jivesoftware.openfire.ldap.LdapManager - LdapManager: Exception thrown when searching for userDN based on username ‘jay’

javax.naming.CommunicationException: MyADServer:389 [Root exception is java.net.ConnectException: Connection timed out: connect]

at com.sun.jndi.ldap.Connection.(Unknown Source)

at com.sun.jndi.ldap.LdapClient.(Unknown Source)

at com.sun.jndi.ldap.LdapClient.getInstance(Unknown Source)

at com.sun.jndi.ldap.LdapCtx.connect(Unknown Source)

at com.sun.jndi.ldap.LdapCtx.(Unknown Source)

at com.sun.jndi.ldap.LdapCtxFactory.getUsingURL(Unknown Source)

at com.sun.jndi.ldap.LdapCtxFactory.getUsingURLs(Unknown Source)

at com.sun.jndi.ldap.LdapCtxFactory.getLdapCtxInstance(Unknown Source)

at com.sun.jndi.ldap.LdapCtxFactory.getInitialContext(Unknown Source)

at javax.naming.spi.NamingManager.getInitialContext(Unknown Source)

at javax.naming.InitialContext.getDefaultInitCtx(Unknown Source)

at javax.naming.InitialContext.init(Unknown Source)

at javax.naming.ldap.InitialLdapContext.(Unknown Source)

at org.jivesoftware.util.JiveInitialLdapContext.(JiveInitialLdapContext.java :43)

at org.jivesoftware.openfire.ldap.LdapManager.getContext(LdapManager.java:568)

Today, I noticed that my AD login was successful for about 25 times, then I saw this connection failing…

Well, again, since it happens randomly, it is kinda hard to reproduce, but this is what I got the log as you requested.

Based on this log, it looks like LdapManager context failing when requested at some point…

BTW, Once I see this connection issue, then…after a while, I am able to login without having any issue again…

Thanks,

Hi Jay,

I’d rather to recommend you to take a look from the other side - I mean from AD side. To understand what’s going on in every case we need a full picture. Can you turn LDAP trace on the AD side and compare events from same timeframe? I’m using this method of analysis every time I have problem with LDAP. Unfortunately I have no AD expertise and unable to help you with LDAP trace in case of AD.

From logs you provided I’d say it looks like AD problem rather than Openfire problem itself. My logic is pretty simple: if that is an Openfire problem, it will be easily reproducible. The only 1 exception here is that problem might appear in time of high CPU load on Openfire - because of such high CPU load there might be time gaps in the time when LDAP ConnectionManager trying to do something and, as a result, any watchdog (if there are any) will stop such “stucked” query after some fixed time (I have no idea regarding how Openfire code works, that’s only my thoughts provided by expertise I have).

Comparing 2 logs: Openfire and AD, will provide much more useful info and ideas. Try to catch both in the time when problem occurs.