13 Replies Latest reply on May 14, 2010 4:07 AM by mputz

    Portal LDAP integration problems

    juhani_g

      Hello,

      I'm am using portal 2.6.4 installed on jboss-4.2.2.GA and trying to integrate Novell eDirectory with portal following the instructions in the ref manual.

      I can't get connection pooling to work. Here's my setup in identity-config.xml (actual values changed obviously):

      <datasources>
       <datasource>
       <name>LDAP</name>
       <config>
       <option>
       <name>host</name>
       <value>ldap.server.fi</value>
       </option>
       <option>
       <name>port</name>
       <value>389</value>
       </option>
       <option>
       <name>adminDN</name>
       <value>cn=sysportaladm,ou=system,dc=foobar,dc=fi</value>
       </option>
       <option>
       <name>adminPassword</name>
       <value>password</value>
       </option>
       </config>
       </datasource>
       </datasources>
      

      The connection work perfectly but it's leaving connection open. This is what netstat says after startup:

      tcp 0 0 portaltest.server:60678 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:59187 ldap.server.fi:ldap ESTABLISHED

      And after a few clicks:

      tcp 0 0 portaltest.server:53923 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:54577 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:50183 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:50343 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:60678 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:59187 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:35797 ldap.server.fi:ldap ESTABLISHED
      tcp 0 0 portaltest.server:33029 ldap.server.fi:ldap ESTABLISHED

      And after searching members in the admin the count is over 80

      Eventually when users use the portal we end up with hundreds of connections and the portal hangs.

      According to the documentation pooling should be working by default?

      I tried to fiddle around with poolingMaxsize, initSize, and prefSize. For instance...

      <option>
       <name>poolingInitsize</name>
       <value>8</value>
       </option>
       <option>
       <name>poolingMaxsize</name>
       <value>16</value>
       </option>
      

      ...didn't have any effect.

      Shouldn't the connection end up as TIME_WAIT (or something) status if they are released properly?

      Well, I tried the ExternalContext way also by defining a mbean in jboss-service.xml without any pooling properties (don't know how to define them there). First I thought everything was working since I got about three connections after server startup in state ESTABLISHED. If the portal isn't used in an hour or so one can't log in - it just hangs and eventually I get the following in the logs:

      2008-04-02 21:16:52,781 ERROR [org.jboss.portal.identity.auth.IdentityLoginModule] Error when validating password
      org.jboss.portal.common.transaction.TransactionException: Abnormal status for ending a tx STATUS_ROLLEDBACK
      at org.jboss.portal.common.transaction.Transactions.end(Transactions.java:437)
      at org.jboss.portal.common.transaction.Transactions$3.noTxAfter(Transactions.java:625)
      at org.jboss.portal.common.transaction.Transactions.apply(Transactions.java:227)
      at org.jboss.portal.common.transaction.Transactions.required(Transactions.java:289)
      at org.jboss.portal.identity.auth.IdentityLoginModule.getUserStatus(IdentityLoginModule.java:223)
      at org.jboss.portal.identity.auth.IdentityLoginModule.validatePassword(IdentityLoginModule.java:177)
      at org.jboss.security.auth.spi.UsernamePasswordLoginModule.login(UsernamePasswordLoginModule.java:210)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at javax.security.auth.login.LoginContext.invoke(LoginContext.java:769)
      at javax.security.auth.login.LoginContext.access$000(LoginContext.java:186)
      at javax.security.auth.login.LoginContext$4.run(LoginContext.java:683)
      at java.security.AccessController.doPrivileged(Native Method)
      at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680)
      at javax.security.auth.login.LoginContext.login(LoginContext.java:579)
      at org.jboss.security.plugins.JaasSecurityManager.defaultLogin(JaasSecurityManager.java:603)
      at org.jboss.security.plugins.JaasSecurityManager.authenticate(JaasSecurityManager.java:537)
      at org.jboss.security.plugins.JaasSecurityManager.isValid(JaasSecurityManager.java:344)
      at org.jboss.web.tomcat.security.JBossSecurityMgrRealm.authenticate(JBossSecurityMgrRealm.java:491)
      at org.apache.catalina.authenticator.FormAuthenticator.authenticate(FormAuthenticator.java:257)
      at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:416)
      at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
      at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
      at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
      at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
      at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:393)
      at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
      at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
      at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
      at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
      at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
      at java.lang.Thread.run(Thread.java:595)
      2008-04-02 21:16:52,782 DEBUG [org.jboss.portal.identity.auth.IdentityLoginModule] Bad password for username=a13577

      Any clues to get this right?

      The organization we are developing the portal for will have atleast 20000 users using it. We will be purchasing the JBoss Enterprise Portal Platform so that we get support if these final evaluations prove that we can use the product.

      Other than this problem things have been pretty straightforward!

      Thanks in advance,
      Juhani

        • 1. Re: Portal LDAP integration problems
          bdaw

          Portal uses standard JNDI pooling. For the JNDI configuration look here:

          http://java.sun.com/products/jndi/tutorial/ldap/connect/pool.html
          http://java.sun.com/products/jndi/tutorial/ldap/connect/config.html

          Options set in ldap_identity-config.xml and standardidentity-config.xml are mapped directly to those. You can use this to configure pooling using ExternalContext. Then you can control whatever you want for the JNDI behaviour.

          If you want to be sure whats the current configuration, go to
          "http://localhost:8080/jmx-console/" and choose "service=Module,type=LDAPConnectionContext". There under "Environment" you'll see all JNDI options used to connect to LDAP listed.

          Did you try playing with timeout and prefsize?

          • 2. Re: Portal LDAP integration problems
            juhani_g

            Thanks for the reply.

            I tried with the following settings:

            <datasource>
             <name>LDAP</name>
             <service-name>portal:service=Module,type=LDAPConnectionContext</service-name>
             <class>org.jboss.portal.identity.ldap.LDAPConnectionContext</class>
             <config>
             <option>
             <name>host</name>
             <value>server</value>
             </option>
             <option>
             <name>port</name>
             <value>389</value>
             </option>
             <option>
             <name>contextFactory</name>
             <value>com.sun.jndi.ldap.LdapCtxFactory</value>
             </option>
             <option>
             <name>adminDN</name>
             <value>dn</value>
             </option>
             <option>
             <name>adminPassword</name>
             <value>pass</value>
             </option>
             <option>
             <name>poolingPrefsize</name>
             <value>20</value>
             </option>
             <option>
             <name>poolingMaxsize</name>
             <value>100</value>
             </option>
             <option>
             <name>poolingTimeout</name>
             <value>5000</value>
             </option>
             <option>
             <name>poolingDebug</name>
             <value>fine</value>
             </option>
             </config>
             </datasource>
             </datasources>


            I'm testing the portal in the admin console - the default portal has some portlets by me that are actually using the portal identity-api. So not touching the just in case they have something to do with this.

            Same thing as before. The setting seem to have no effect. When I do the user search it opens tens of connections according to netstat. I'm not seen any debug anywhere even though using the debug option. Where should I find the debugging logs?

            In the jmx-console I can see that the pooling properties seem to be correct. However, clicking a few times on search users I end up with way over hunder connections.

            At this point I decided to play around with JAVA_OPTS and added:
            -Dcom.sun.jndi.ldap.connect.pool.debug=fine -Dcom.sun.jndi.ldap.connect.pool=true
            to JAVA_OPTS in run.conf

            This seem to activate the pooling or at least the debug! The first click (portal admin console) results in this in STRERR:

            22:17:45,188 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,191 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,192 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,193 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,194 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,195 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,196 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,197 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,198 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,199 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,199 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:17:45,201 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791

            Now when I click Members tab, everything seems fine again except for one connection not getting released (quite a few connections used for one click btw):
            22:19:57,735 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@1ae48504
            22:19:57,801 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,803 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,805 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,806 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,807 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,808 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,809 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,810 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,810 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,812 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,812 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:19:57,814 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4ceb1c86

            Now clicking search users:
            22:21:39,217 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4ceb1c86
            22:21:39,249 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@31f3f16b
            22:21:39,253 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@541d4bce
            22:21:39,255 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@541d4bce
            22:21:39,255 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@541d4bce
            22:21:39,258 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:21:39,260 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@17965791
            22:21:39,260 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@17965791
            22:21:39,263 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@c3f8d48[sedi1.replaced.fi:389]
            22:21:39,266 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@c3f8d48
            22:21:39,266 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@c3f8d48
            22:21:39,270 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@20547840[sedi1.replaced.fi:389]
            22:21:39,272 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@20547840
            22:21:39,273 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@20547840
            22:21:39,283 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@42e579f9[sedi1.replaced.fi:389]
            22:21:39,289 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@67aaecbe[sedi1.replaced.fi:389]
            22:21:39,294 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@69ce31e[sedi1.replaced.fi:389]
            22:21:39,301 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@2602c9f6[sedi1.replaced.fi:389]
            22:21:39,305 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@11948f9[sedi1.replaced.fi:389]
            22:21:39,307 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@11948f9
            22:21:39,308 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@11948f9
            22:21:39,311 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@2305d3ff[sedi1.replaced.fi:389]
            22:21:39,313 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@2305d3ff
            22:21:39,314 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@2305d3ff
            22:21:39,317 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@53a11c4f[sedi1.replaced.fi:389]
            22:21:39,319 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@53a11c4f
            22:21:39,320 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@53a11c4f
            22:21:39,323 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@7649b16d[sedi1.replaced.fi:389]
            22:21:39,325 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@7649b16d
            22:21:39,325 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@7649b16d
            22:21:39,335 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@2e24655f[sedi1.replaced.fi:389]
            22:21:39,340 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@577b57a3[sedi1.replaced.fi:389]
            22:21:39,345 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@591686f7[sedi1.replaced.fi:389]
            22:21:39,352 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4a8171b[sedi1.replaced.fi:389]
            22:21:39,356 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3784f000[sedi1.replaced.fi:389]
            22:21:39,358 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@3784f000
            22:21:39,359 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@3784f000
            22:21:39,362 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@78a8ac79[sedi1.replaced.fi:389]
            22:21:39,364 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@78a8ac79
            22:21:39,365 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@78a8ac79
            22:21:39,368 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@1ae2cf08[sedi1.replaced.fi:389]
            22:21:39,370 ERROR [LDAPUserProfileModuleImpl] No such attribute ('givenName') in entry: cn=jukkatv,ou=People,dc=replaced,dc=fi
            22:21:39,370 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@1ae2cf08
            22:21:39,371 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@1ae2cf08
            22:21:39,374 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@20862402[sedi1.replaced.fi:389]
            22:21:39,376 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@20862402
            22:21:39,377 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@20862402
            22:21:39,389 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@784ee63e[sedi1.replaced.fi:389]
            22:21:39,394 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3ee2e27[sedi1.replaced.fi:389]
            22:21:39,405 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@447798a9[sedi1.replaced.fi:389]
            22:21:39,411 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@7c7a25d[sedi1.replaced.fi:389]
            22:21:39,416 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@43748ba8[sedi1.replaced.fi:389]
            22:21:39,418 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@43748ba8
            22:21:39,419 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@43748ba8
            22:21:39,422 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@187ce531[sedi1.replaced.fi:389]
            22:21:39,424 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@187ce531
            22:21:39,425 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@187ce531
            22:21:39,428 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@2fab0086[sedi1.replaced.fi:389]
            22:21:39,430 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@2fab0086
            22:21:39,431 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@2fab0086
            22:21:39,434 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3af75dd[sedi1.replaced.fi:389]
            22:21:39,436 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@3af75dd
            22:21:39,437 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@3af75dd
            22:21:39,446 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@512733fc[sedi1.replaced.fi:389]
            22:21:39,451 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@64c60f03[sedi1.replaced.fi:389]
            22:21:39,456 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@703c1a5[sedi1.replaced.fi:389]
            22:21:39,463 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4a89e2f0[sedi1.replaced.fi:389]
            22:21:39,469 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@229220cb[sedi1.replaced.fi:389]
            22:21:39,471 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@229220cb
            22:21:39,472 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@229220cb
            22:21:39,475 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@27a70128[sedi1.replaced.fi:389]
            22:21:39,477 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@27a70128
            22:21:39,478 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@27a70128
            22:21:39,481 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@453cfd6e[sedi1.replaced.fi:389]
            22:21:39,483 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@453cfd6e
            22:21:39,484 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@453cfd6e
            22:21:39,487 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@27226445[sedi1.replaced.fi:389]
            22:21:39,489 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@27226445
            22:21:39,490 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@27226445
            22:21:39,499 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@8f74d2f[sedi1.replaced.fi:389]
            22:21:39,504 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@23ec4d42[sedi1.replaced.fi:389]
            22:21:39,510 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@6ec43a7a[sedi1.replaced.fi:389]
            22:21:39,516 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@14db5866[sedi1.replaced.fi:389]
            22:21:39,520 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4c889b3c[sedi1.replaced.fi:389]
            22:21:39,522 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@4c889b3c
            22:21:39,522 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@4c889b3c
            22:21:39,525 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@1c87a765[sedi1.replaced.fi:389]
            22:21:39,528 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@1c87a765
            22:21:39,528 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@1c87a765
            22:21:39,531 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@dfee685[sedi1.replaced.fi:389]
            22:21:39,533 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@dfee685
            22:21:39,534 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@dfee685
            22:21:39,537 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@59d02cf0[sedi1.replaced.fi:389]
            22:21:39,539 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@59d02cf0
            22:21:39,540 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@59d02cf0
            22:21:39,549 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@f2ceb70[sedi1.replaced.fi:389]
            22:21:39,554 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4e150dd8[sedi1.replaced.fi:389]
            22:21:39,559 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@484007f4[sedi1.replaced.fi:389]
            22:21:39,565 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@63ca493a[sedi1.replaced.fi:389]
            22:21:39,570 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@758db204[sedi1.replaced.fi:389]
            22:21:39,572 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@758db204
            22:21:39,573 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@758db204
            22:21:39,576 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@29a260e7[sedi1.replaced.fi:389]
            22:21:39,578 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@29a260e7
            22:21:39,579 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@29a260e7
            22:21:39,582 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@6387f30b[sedi1.replaced.fi:389]
            22:21:39,585 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6387f30b
            22:21:39,585 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6387f30b
            22:21:39,588 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@72658a39[sedi1.replaced.fi:389]
            22:21:39,591 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@72658a39
            22:21:39,591 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@72658a39
            22:21:39,600 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@71d418d7[sedi1.replaced.fi:389]
            22:21:39,606 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@1bab05a3[sedi1.replaced.fi:389]
            22:21:39,611 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@78ff1e85[sedi1.replaced.fi:389]
            22:21:39,617 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@352cebd2[sedi1.replaced.fi:389]
            22:21:39,621 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@182e4344[sedi1.replaced.fi:389]
            22:21:39,624 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@182e4344
            22:21:39,624 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@182e4344
            22:21:39,628 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@54231c3[sedi1.replaced.fi:389]
            22:21:39,630 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@54231c3
            22:21:39,631 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@54231c3
            22:21:39,634 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3cd0fbe7[sedi1.replaced.fi:389]
            22:21:39,636 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@3cd0fbe7
            22:21:39,637 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@3cd0fbe7
            22:21:39,640 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3c4a19e2[sedi1.replaced.fi:389]
            22:21:39,642 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@3c4a19e2
            22:21:39,643 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@3c4a19e2
            22:21:39,652 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4c6cea8a[sedi1.replaced.fi:389]
            22:21:39,658 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@29a3139[sedi1.replaced.fi:389]
            22:21:39,664 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@59159684[sedi1.replaced.fi:389]
            22:21:39,670 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@184ce1cd[sedi1.replaced.fi:389]
            22:21:39,674 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@5f7c6631[sedi1.replaced.fi:389]
            22:21:39,677 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@5f7c6631
            22:21:39,677 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@5f7c6631
            22:21:39,680 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@60194bf0[sedi1.replaced.fi:389]
            22:21:39,683 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@60194bf0
            22:21:39,683 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@60194bf0
            22:21:39,686 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@3a48dcf9[sedi1.replaced.fi:389]
            22:21:39,688 ERROR [LDAPUserProfileModuleImpl] No such attribute ('givenName') in entry: cn=a2104,ou=People,dc=replaced,dc=fi
            22:21:39,689 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@3a48dcf9
            22:21:39,689 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@3a48dcf9
            22:21:39,692 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@5a37d54[sedi1.replaced.fi:389]
            22:21:39,694 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@5a37d54
            22:21:39,695 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@5a37d54
            22:21:39,704 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@4168c350[sedi1.replaced.fi:389]
            22:21:39,710 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@44eedabc[sedi1.replaced.fi:389]
            22:21:39,715 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@1d5a8fff[sedi1.replaced.fi:389]
            22:21:39,721 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@79e7c7fb[sedi1.replaced.fi:389]
            22:21:39,725 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@5ffa6e43[sedi1.replaced.fi:389]
            22:21:39,727 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@5ffa6e43
            22:21:39,728 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@5ffa6e43
            22:21:39,731 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@325d21ef[sedi1.replaced.fi:389]
            22:21:39,733 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@325d21ef
            22:21:39,734 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@325d21ef
            22:21:39,737 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@5eebbe[sedi1.replaced.fi:389]
            22:21:39,739 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@5eebbe
            22:21:39,740 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@5eebbe
            22:21:39,743 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@57c70722[sedi1.replaced.fi:389]
            22:21:39,745 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@57c70722
            22:21:39,745 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@57c70722
            22:21:39,755 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@632c17b6[sedi1.replaced.fi:389]
            22:21:39,761 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@63c8e097[sedi1.replaced.fi:389]
            22:21:39,766 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@19110caf[sedi1.replaced.fi:389]
            22:21:39,812 ERROR [STDERR] Create and use com.sun.jndi.ldap.LdapClient@6fe03f3b[sedi1.replaced.fi:389]
            22:21:39,815 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,817 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,818 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,818 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,820 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,820 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,822 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,822 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,824 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,824 ERROR [STDERR] Use com.sun.jndi.ldap.LdapClient@6fe03f3b
            22:21:39,825 ERROR [STDERR] Release com.sun.jndi.ldap.LdapClient@6fe03f3b

            And I end up with 83 established connections. The above debug has a count of 78 for "Create and use" and 46 for "Release".

            When I shutdown the server I can see the debug information that the connections are released.

            Now I added some more options for JAVA_OPTS:
            -Dcom.sun.jndi.ldap.connect.pool.maxsize=40 -Dcom.sun.jndi.ldap.connect.pool.prefsize=20 -Dcom.sun.jndi.ldap.connect.pool.timeout=5000

            Now the timeout kicks in (notice I had 5000 also in the portal config which didn't have any effect), I get lines like:
            22:31:09,184 ERROR [STDERR] Expired com.sun.jndi.ldap.LdapClient@3fd4714d expired

            And the connections are in TIME_WAIT according to netstat!

            So looking good but the user search causes connections leaks again and proves that the maxsize 40 is working since one user search is enough to get the portal hang and it's not getting any connections after 40.

            Btw, I have Mysql5 setup as the portal database, but that shouldn't have anything to do with this, right?

            So something is causing the connections not been released. I'm suspecting the ProfileModule since this leaking seems to happen everytime user properties is been fetched (user search for example). What would be the best way to debug this problem?

            I will try to play around with the external context approach tomorrow but getting a bit frustrated. With external context none of those JAVA_OPTS I tried had any effect. Has anybody got a good pooling example done with external context?

            • 3. Re: Portal LDAP integration problems
              juhani_g

              Quick update:

              Looking at the source the problem seems to be with method searchUsers in class LDAPExtUserModuleImpl. I added some debugging to verify that ldapContext.close() is been called - and it is.

              Having pooling logging turned on I can see that even though ldapContext.close() is called the connection isn't released. On the other hand ldapContext.close() in method getProperty in LDAPUserProfileModuleImpl is releasing the connection.

              Then I read this: http://blogs.warwick.ac.uk/kieranshaw/entry/ldap_connection_pooling/

              It's says there that one should close NamingEnumeration - which you don't do in searchUsers.

              • 4. Re: Portal LDAP integration problems
                juhani_g

                Update 2:

                I think I found at least one part of the code that is causing problems:

                It is findUserByUserName(String userName) in LDAPExtUserModuleImpl (that uses searchUsers).

                I changed the code:

                SearchResult res = (SearchResult)sr.iterator().next();
                 Context ctx = (Context)res.getObject();
                 String dn = ctx.getNameInNamespace();
                
                 return createUserInstance(res.getAttributes(), dn);


                With:

                SearchResult res = (SearchResult)sr.iterator().next();
                 Context ctx = (Context)res.getObject();
                 String dn = ctx.getNameInNamespace();
                 User user = createUserInstance(res.getAttributes(), dn);
                 System.err.println("CREATED USER AND CLOSE CONTEXT");
                 ctx.close();
                 return user;


                Now the Context is closed and caused the connection to be released right away (according to the pooling debug messages).

                Continuing with experiments.

                In any case, I do think the LDAP code needs optimizing. Is there any technical documentation on it available?

                • 5. Re: Portal LDAP integration problems
                  bdaw

                  This indeed looks like a bug. Could you create a JIRA with a patch and reference to this thread?

                  • 6. Re: Portal LDAP integration problems
                    juhani_g

                    Ok, I will do that ASAP.

                    • 7. Re: Portal LDAP integration problems
                      bdaw

                      I improved the code a bit and with my test number of open connections always remains low and related to poolingMaxsize. Could you try it out?

                      http://anonsvn.jboss.org/repos/portal/modules/identity/branches/JBP_IDENTITY_BRANCH_1_0/




                      • 8. Re: Portal LDAP integration problems
                        bdaw

                        btw. I'm not sure your take on TIME_WAIT is correct. Creating a connection is costly so keeping the pool of open ones and reuse gives performance gain.

                        • 9. Re: Portal LDAP integration problems
                          bdaw

                          and one more thing for the configuration. You are right that timeout setting for LDAPConnectionContext doesn't work. It seesm that these option must be specified in java opts as you did:

                          http://java.sun.com/products/jndi/tutorial/ldap/connect/config.html

                          "Note that these are system properties, not environment properties and that they affect all connection pooling requests."


                          • 10. Re: Portal LDAP integration problems
                            mputz
                            • 11. Re: Portal LDAP integration problems
                              juhani_g

                               

                              "bdaw" wrote:
                              I improved the code a bit and with my test number of open connections always remains low and related to poolingMaxsize. Could you try it out?
                              http://anonsvn.jboss.org/repos/portal/modules/identity/branches/JBP_IDENTITY_BRANCH_1_0/




                              Ok I'll give it a try soon. I've been so busy that I haven't had time to dig in to this more. I got it working with my patch well enough for the time being...

                              "bdaw" wrote:
                              btw. I'm not sure your take on TIME_WAIT is correct. Creating a connection is costly so keeping the pool of open ones and reuse gives performance gain.


                              Yes, I got the TIME_WAIT thing wrong.

                              • 12. Re: Portal LDAP integration problems
                                irishfan99ko

                                I am running into what looks like the exact same problem with version 2.7.0. Is there any chance that 2.7.0 missed the fix?

                                • 13. Re: Portal LDAP integration problems
                                  mputz

                                  Is there any chance that 2.7.0 missed the fix?

                                   

                                  No, JBPORTAL-1996 has been applied to the 2.7 branch as well. But some additional leaks have been discovered, see https://jira.jboss.org/jira/browse/JBPORTAL-2476. This has been fixed in the JBP_IDENTITY_BRANCH_1_1 already.