Details

    • Type: Bug Bug
    • Status: Closed
    • Resolution: Won't Fix
    • Affects Version/s: 6.0.X EE, 6.1.30 EE GA3, 6.2.0 CE M3
    • Labels:
      None
    • Environment:
    • Fix Priority:
      4
    • Similar Issues:
      Show 5 results 

      Description

      1. Include the following property in the portal-ext.properties file (The default value is 15 seconds):

      ldap.connection.com.sun.jndi.ldap.read.timeout=500

      2. Restart the portal and run a load test script that simply logs a user in and out repeatedly. Alternatively, configure the portal to do a LDAP import on start-up. Basically any action that will produce a large number of LDAP requests for data retrieved from LDAP.(Example: 5500 users)
      3. Check the log files for any LDAP read-timeout errors.

      Search user in LDAP throw error message in console:

      05:13:08,835 ERROR [liferay/scheduler_dispatch-3][PortalLDAPImporterImpl:700] Unable to import user cn=qa2675,ou=users,dc=Name: null:null:{cn=cn: qa26
      75}
      javax.naming.NamingException: LDAP response read timed out, timeout used:500ms.; remaining name 'dc=example,dc=com'
              at com.sun.jndi.ldap.Connection.readReply(Connection.java:448)
              at com.sun.jndi.ldap.LdapClient.getSearchReply(LdapClient.java:611)
              at com.sun.jndi.ldap.LdapClient.search(LdapClient.java:534)
              at com.sun.jndi.ldap.LdapCtx.doSearch(LdapCtx.java:1962)
              at com.sun.jndi.ldap.LdapCtx.searchAux(LdapCtx.java:1824)
              at com.sun.jndi.ldap.LdapCtx.c_search(LdapCtx.java:1749)
              at com.sun.jndi.toolkit.ctx.ComponentDirContext.p_search(ComponentDirContext.java:368)
              at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:338)
              at com.sun.jndi.toolkit.ctx.PartialCompositeDirContext.search(PartialCompositeDirContext.java:321)
              at javax.naming.directory.InitialDirContext.search(InitialDirContext.java:248)
              at com.liferay.portal.security.ldap.PortalLDAPUtil.getUser(PortalLDAPUtil.java:488)
              at com.liferay.portal.security.ldap.PortalLDAPImporterImpl.importGroups(PortalLDAPImporterImpl.java:790)
              at com.liferay.portal.security.ldap.PortalLDAPImporterImpl.importFromLDAPByUser(PortalLDAPImporterImpl.java:695)
              at com.liferay.portal.security.ldap.PortalLDAPImporterImpl.importFromLDAP(PortalLDAPImporterImpl.java:200)
              at com.liferay.portal.security.ldap.PortalLDAPImporterImpl.importFromLDAP(PortalLDAPImporterImpl.java:137)
              at com.liferay.portal.security.ldap.PortalLDAPImporterUtil.importFromLDAP(PortalLDAPImporterUtil.java:43)
              at com.liferay.portlet.admin.messaging.LDAPImportMessageListener.doImportOnStartup(LDAPImportMessageListener.java:38)
              at com.liferay.portlet.admin.messaging.LDAPImportMessageListener.doReceive(LDAPImportMessageListener.java:48)
              at com.liferay.portal.kernel.messaging.BaseMessageListener.receive(BaseMessageListener.java:25)
              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:597)
              at com.liferay.portal.kernel.bean.ClassLoaderBeanHandler.invoke(ClassLoaderBeanHandler.java:67)
              at $Proxy283.receive(Unknown Source)
              at com.liferay.portal.kernel.scheduler.messaging.SchedulerEventMessageListenerWrapper.receive(SchedulerEventMessageListenerWrapper.java:75)
              at com.liferay.portal.kernel.messaging.InvokerMessageListener.receive(InvokerMessageListener.java:63)
              at com.liferay.portal.kernel.messaging.ParallelDestination$1.run(ParallelDestination.java:68)
              at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask._runTask(ThreadPoolExecutor.java:671)
              at com.liferay.portal.kernel.concurrent.ThreadPoolExecutor$WorkerTask.run(ThreadPoolExecutor.java:582)
              at java.lang.Thread.run(Thread.java:662)
      

        Issue Links

          Activity

          Hide
          Juan G added a comment - - edited

          Happens same to our Liferay 6.1.1. We have a 60s timeout in LDAP servers, and is always failing when importing massive users.

          I guess this is caused by the reuse of the same connection for every LDAP queries, so is easy to get this timeout.

          I tried using LDAP connection pool, but same error arises.

          Show
          Juan G added a comment - - edited Happens same to our Liferay 6.1.1. We have a 60s timeout in LDAP servers, and is always failing when importing massive users. I guess this is caused by the reuse of the same connection for every LDAP queries, so is easy to get this timeout. I tried using LDAP connection pool, but same error arises.
          Hide
          Juan G added a comment -

          Seems problem is bigger than initially guessed.

          After some days, some PermGen exceptions appear, and happened just after log in using LDAP. Perhaps there is a memory leak here...

          Show
          Juan G added a comment - Seems problem is bigger than initially guessed. After some days, some PermGen exceptions appear, and happened just after log in using LDAP. Perhaps there is a memory leak here...
          Hide
          Juan G added a comment -

          Any updates on this issue?

          Show
          Juan G added a comment - Any updates on this issue?
          Hide
          Graeme Steyn added a comment -

          Hi Juan,

          I had a breif response from our systems admininstrator about our LDAP performance and got the following as possible causes for the slow performance of our LDAP system ("The ldap query is taking 11 seconds to run on test, but it takes <1s to run on production").

          • "No I haven't had a chance to find out what it is. If I had to guess I'd say the hardware it's running on. The old sun hardware runs low on memory, as the queries that liferay does on the LDAP servers flog the hell out of it and it caches everything. This then causes it to go to swap so things swap out and in as needed."

          The original investigation that I did resulted in the changes as outlined in LPS-28638, LPS-28639 and LPS-28640. I was still experiencing the following in our test environment.

          I have finished going through the code and introduced 2 optimizations and some fixes for the returning of the connections to the LDAP pool.  The LDAP connection pool is now working correctly.  However, there are still very long response times involved in the test environment.  Here is an extract of some of the logging that I have introduced to get a better idea of where the time is being spent (last figure on logging line is time in ms from some custom timers inserted at specific points).
           
                          1543       2012-07-18 03:21:47,005 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 02 Get OpenSSO Attributes in OpenSSOAutoLogin 31
                          1544       2012-07-18 03:21:47,006 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 03 Check for existing user in OpenSSOAutoLogin 0
                          1545       2012-07-18 03:21:47,020 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 14 Search for User in importLDAPUser 2
                          1588       2012-07-18 03:21:58,582 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 15 Get user attibutes in importLDAPUser 11561
                          1593       2012-07-18 03:21:58,598 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 08 Import User in PortalLDAPImporterImpl 16
                          1596       2012-07-18 03:21:58,648 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] (&(&(ou:dn:=groups)(objectClass=groupOfUniqueNames)(uniqueMember=*))(uniqueMember=uid=s0184076,ou=people,dc=cqu,dc=edu,dc=au))
                          1653       2012-07-18 03:22:15,748 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 11 PortalLDAPUtil.searchLDAP 17100
                          1660       2012-07-18 03:22:17,225 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 12 Add and delete useer from groups 1477
                          1661       2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 09 Import Groups in PortalLDAPImporterImpl 18631
                          1662       2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 10 importLDAPUser in PortalLDAPImporterImpl 30224
                          1663       2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 04 LDAP user import SN in OpenSSOAutoLogin 30224
                          1664       2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 07 User NULL check in OpenSSOAutoLogin 0   
           
          From the section above and from thread dumps that I have being taking there appear to be two hot spots.
           
          1.      (&(&(ou:dn:=groups)(objectClass=groupOfUniqueNames)(uniqueMember=*))(uniqueMember=uid=xxxx,ou=people,dc=xxx,dc=xxx,dc=xx)) = 17.1 seconds to return.
          2.      Another query that gets the LDAP properties for a group using the groups FullDN, e.g. cn=all-students,ou=groups,dc=xxx,dc=xxx,dc=xx.  The LDAP properties that it retrieves are: cn, description, creatorsName, createTimestamp, modifiersName, modifyTimestamp  - this query often appears to have threads waiting for a lock.
          3.      Retrieving the user’s attributes is also slow at about 11.561 seconds.  This is normally a query using the Full DN for the user and a list of specified attributes values to retrieve, e.g. uid, mail, givenName, sn, title, displayName, isMemberOf, creatorsName, createTimestamp, modifiersName, modifyTimeStamp.
           
          I have done as much as I can in the current code.
          

          Hope some of this helps.

          Show
          Graeme Steyn added a comment - Hi Juan, I had a breif response from our systems admininstrator about our LDAP performance and got the following as possible causes for the slow performance of our LDAP system ("The ldap query is taking 11 seconds to run on test, but it takes <1s to run on production"). "No I haven't had a chance to find out what it is. If I had to guess I'd say the hardware it's running on. The old sun hardware runs low on memory, as the queries that liferay does on the LDAP servers flog the hell out of it and it caches everything. This then causes it to go to swap so things swap out and in as needed." The original investigation that I did resulted in the changes as outlined in LPS-28638 , LPS-28639 and LPS-28640 . I was still experiencing the following in our test environment. I have finished going through the code and introduced 2 optimizations and some fixes for the returning of the connections to the LDAP pool. The LDAP connection pool is now working correctly. However, there are still very long response times involved in the test environment. Here is an extract of some of the logging that I have introduced to get a better idea of where the time is being spent (last figure on logging line is time in ms from some custom timers inserted at specific points). 1543 2012-07-18 03:21:47,005 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 02 Get OpenSSO Attributes in OpenSSOAutoLogin 31 1544 2012-07-18 03:21:47,006 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 03 Check for existing user in OpenSSOAutoLogin 0 1545 2012-07-18 03:21:47,020 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 14 Search for User in importLDAPUser 2 1588 2012-07-18 03:21:58,582 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 15 Get user attibutes in importLDAPUser 11561 1593 2012-07-18 03:21:58,598 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 08 Import User in PortalLDAPImporterImpl 16 1596 2012-07-18 03:21:58,648 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] (&(&(ou:dn:=groups)(objectClass=groupOfUniqueNames)(uniqueMember=*))(uniqueMember=uid=s0184076,ou=people,dc=cqu,dc=edu,dc=au)) 1653 2012-07-18 03:22:15,748 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 11 PortalLDAPUtil.searchLDAP 17100 1660 2012-07-18 03:22:17,225 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 12 Add and delete useer from groups 1477 1661 2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 09 Import Groups in PortalLDAPImporterImpl 18631 1662 2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.ldap.PortalLDAPImporterImpl:?] 10 importLDAPUser in PortalLDAPImporterImpl 30224 1663 2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 04 LDAP user import SN in OpenSSOAutoLogin 30224 1664 2012-07-18 03:22:17,230 [INFO ] [tomcat-http--34] [com.liferay.portal.security.auth.OpenSSOAutoLogin:?] 07 User NULL check in OpenSSOAutoLogin 0 From the section above and from thread dumps that I have being taking there appear to be two hot spots. 1. (&(&(ou:dn:=groups)(objectClass=groupOfUniqueNames)(uniqueMember=*))(uniqueMember=uid=xxxx,ou=people,dc=xxx,dc=xxx,dc=xx)) = 17.1 seconds to return. 2. Another query that gets the LDAP properties for a group using the groups FullDN, e.g. cn=all-students,ou=groups,dc=xxx,dc=xxx,dc=xx. The LDAP properties that it retrieves are: cn, description, creatorsName, createTimestamp, modifiersName, modifyTimestamp - this query often appears to have threads waiting for a lock. 3. Retrieving the user’s attributes is also slow at about 11.561 seconds. This is normally a query using the Full DN for the user and a list of specified attributes values to retrieve, e.g. uid, mail, givenName, sn, title, displayName, isMemberOf, creatorsName, createTimestamp, modifiersName, modifyTimeStamp. I have done as much as I can in the current code. Hope some of this helps.
          Hide
          Mika Koivisto added a comment -

          The property ldap.connection.com.sun.jndi.ldap.read.timeout=500 sets the LDAP query read timeout to 500ms and any query that takes longer will be interrupted with an exception and this is exactly what's happening so it's working as it should.

          Show
          Mika Koivisto added a comment - The property ldap.connection.com.sun.jndi.ldap.read.timeout=500 sets the LDAP query read timeout to 500ms and any query that takes longer will be interrupted with an exception and this is exactly what's happening so it's working as it should.

            People

            • Votes:
              2 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:
                Days since last comment:
                1 year, 24 weeks ago

                Development

                  Structure Helper Panel