Uploaded image for project: 'OpenAM'
  1. OpenAM
  2. OPENAM-8202

If the "Login Id" in the External Store Configuration(CTS) is set to incorrect value,CoreSystem debug log is full of duplicate error

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 13.0.0, 13.5.0
    • Fix Version/s: 13.5.1, 14.0.0
    • Component/s: CTS
    • Labels:
    • Environment:
      OpenAM 13.0.0 Build 5d4589530d (2016-January-14 21:15)
      CTS: OpenDJ 2.6.3
    • Sprint:
      AM Sustaining Sprint 29, AM Sustaining Sprint 30, AM Sustaining Sprint 31
    • Story Points:
      3
    • Support Ticket IDs:

      Description

      CoreSystem debug log is growing extreme fast with duplicate error until disk will be full, when the "Login Id" in the External Store Configuration(CTS) is set to incorrect value.

      Steps to reproduce:

      1.) Install OpenAM with OpenDJ Directory Service for CTS
      https://qa-backstage.forgerock.com/#!/docs/openam/13/install-guide#cts-opendj-preparation
      2.) At the step "6.2.5. OpenAM CTS Configuration" set to incorrect value for "Login Id" (in my case correct value was "cn=Directory Manager" and I set it to "cn=Directory ManagerXXX" )
      3.) Restart OpenAM
      4.) Observe /openam/openam/debug/CoreSystem log

      Observed result:

      The log file is full of the same error and size of file is growing very fast. In my case log file had 11GB(my limit of free space on HDD) after few minutes.

      Expected Result

      Error appears only once or the process will finished after few times of restarting Thread WatchDog

      CoreSystem debug log:

      amThreadManager:01/26/2016 02:14:47:633 PM GMT: Thread[amThreadManager-1,5,ServerService ThreadGroup]: TransactionId[300c2122-7500-4b31-abdc-39a19681ff30-2]
      ERROR: ThreadMonitor: Thread WatchDog detected error, restarting
      java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Cannot start task executor
      	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
      	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
      	at org.forgerock.openam.shared.concurrency.ThreadMonitor$WatchDog.run(ThreadMonitor.java:231)
      	at org.forgerock.openam.audit.context.AuditRequestContextPropagatingRunnable.run(AuditRequestContextPropagatingRunnable.java:42)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.IllegalStateException: Cannot start task executor
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:85)
      	... 6 more
      Caused by: org.forgerock.openam.sm.datalayer.api.LdapOperationFailedException: 
      CTS: Operation failed:
      Result Code: Connect Error
      Diagnostic Message: No operational connection factories available
      Matched DN: 
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:158)
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:126)
      	at org.forgerock.openam.cts.monitoring.impl.connections.MonitoredCTSConnectionFactory.create(MonitoredCTSConnectionFactory.java:71)
      	at org.forgerock.openam.sm.datalayer.impl.SimpleTaskExecutor.start(SimpleTaskExecutor.java:59)
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:83)
      	... 6 more
      Caused by: org.forgerock.opendj.ldap.AuthenticationException: Invalid Credentials
      	at org.forgerock.opendj.ldap.LdapException.newLdapException(LdapException.java:150)
      	at org.forgerock.opendj.ldap.spi.ResultLdapPromiseImpl.setResultOrError(ResultLdapPromiseImpl.java:142)
      	at org.forgerock.opendj.grizzly.LDAPClientFilter$ClientResponseHandler.bindResult(LDAPClientFilter.java:192)
      	at org.forgerock.opendj.io.LDAPReader.readBindResult(LDAPReader.java:217)
      	at org.forgerock.opendj.io.LDAPReader.readProtocolOp(LDAPReader.java:550)
      	at org.forgerock.opendj.io.LDAPReader.readMessage(LDAPReader.java:132)
      	at org.forgerock.opendj.grizzly.LDAPBaseFilter.handleRead(LDAPBaseFilter.java:82)
      	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111)
      	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
      	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536)
      	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:591)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:571)
      	... 1 more
      
      amThreadManager:01/26/2016 02:14:47:633 PM GMT: Thread[amThreadManager-8,5,ServerService ThreadGroup]: TransactionId[300c2122-7500-4b31-abdc-39a19681ff30-2]
      ERROR: ThreadMonitor: Thread WatchDog detected error, restarting
      java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Cannot start task executor
      	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
      	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
      	at org.forgerock.openam.shared.concurrency.ThreadMonitor$WatchDog.run(ThreadMonitor.java:231)
      	at org.forgerock.openam.audit.context.AuditRequestContextPropagatingRunnable.run(AuditRequestContextPropagatingRunnable.java:42)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.IllegalStateException: Cannot start task executor
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:85)
      	... 6 more
      Caused by: org.forgerock.openam.sm.datalayer.api.LdapOperationFailedException: 
      CTS: Operation failed:
      Result Code: Connect Error
      Diagnostic Message: No operational connection factories available
      Matched DN: 
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:158)
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:126)
      	at org.forgerock.openam.cts.monitoring.impl.connections.MonitoredCTSConnectionFactory.create(MonitoredCTSConnectionFactory.java:71)
      	at org.forgerock.openam.sm.datalayer.impl.SimpleTaskExecutor.start(SimpleTaskExecutor.java:59)
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:83)
      	... 6 more
      Caused by: org.forgerock.opendj.ldap.AuthenticationException: Invalid Credentials
      	at org.forgerock.opendj.ldap.LdapException.newLdapException(LdapException.java:150)
      	at org.forgerock.opendj.ldap.spi.ResultLdapPromiseImpl.setResultOrError(ResultLdapPromiseImpl.java:142)
      	at org.forgerock.opendj.grizzly.LDAPClientFilter$ClientResponseHandler.bindResult(LDAPClientFilter.java:192)
      	at org.forgerock.opendj.io.LDAPReader.readBindResult(LDAPReader.java:217)
      	at org.forgerock.opendj.io.LDAPReader.readProtocolOp(LDAPReader.java:550)
      	at org.forgerock.opendj.io.LDAPReader.readMessage(LDAPReader.java:132)
      	at org.forgerock.opendj.grizzly.LDAPBaseFilter.handleRead(LDAPBaseFilter.java:82)
      	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111)
      	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
      	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536)
      	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:591)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:571)
      	... 1 more
      
      amThreadManager:01/26/2016 02:14:47:633 PM GMT: Thread[amThreadManager-12,5,ServerService ThreadGroup]: TransactionId[300c2122-7500-4b31-abdc-39a19681ff30-2]
      ERROR: ThreadMonitor: Thread WatchDog detected error, restarting
      java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Cannot start task executor
      	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
      	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
      	at org.forgerock.openam.shared.concurrency.ThreadMonitor$WatchDog.run(ThreadMonitor.java:231)
      	at org.forgerock.openam.audit.context.AuditRequestContextPropagatingRunnable.run(AuditRequestContextPropagatingRunnable.java:42)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at java.lang.Thread.run(Thread.java:745)
      Caused by: java.lang.IllegalStateException: Cannot start task executor
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:85)
      	... 6 more
      Caused by: org.forgerock.openam.sm.datalayer.api.LdapOperationFailedException: 
      CTS: Operation failed:
      Result Code: Connect Error
      Diagnostic Message: No operational connection factories available
      Matched DN: 
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:158)
      	at org.forgerock.openam.sm.datalayer.providers.LdapConnectionFactoryProvider$LdapConnectionFactory.create(LdapConnectionFactoryProvider.java:126)
      	at org.forgerock.openam.cts.monitoring.impl.connections.MonitoredCTSConnectionFactory.create(MonitoredCTSConnectionFactory.java:71)
      	at org.forgerock.openam.sm.datalayer.impl.SimpleTaskExecutor.start(SimpleTaskExecutor.java:59)
      	at org.forgerock.openam.sm.datalayer.impl.SeriesTaskExecutorThread.run(SeriesTaskExecutorThread.java:83)
      	... 6 more
      Caused by: org.forgerock.opendj.ldap.AuthenticationException: Invalid Credentials
      	at org.forgerock.opendj.ldap.LdapException.newLdapException(LdapException.java:150)
      	at org.forgerock.opendj.ldap.spi.ResultLdapPromiseImpl.setResultOrError(ResultLdapPromiseImpl.java:142)
      	at org.forgerock.opendj.grizzly.LDAPClientFilter$ClientResponseHandler.bindResult(LDAPClientFilter.java:192)
      	at org.forgerock.opendj.io.LDAPReader.readBindResult(LDAPReader.java:217)
      	at org.forgerock.opendj.io.LDAPReader.readProtocolOp(LDAPReader.java:550)
      	at org.forgerock.opendj.io.LDAPReader.readMessage(LDAPReader.java:132)
      	at org.forgerock.opendj.grizzly.LDAPBaseFilter.handleRead(LDAPBaseFilter.java:82)
      	at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132)
      	at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111)
      	at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77)
      	at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536)
      	at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56)
      	at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:591)
      	at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:571)
      	... 1 more
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                quentin.castel Quentin CASTEL
                Reporter:
                richard.hruza Richard Hruza
                QA Assignee:
                Nemanja Lukic
              • Votes:
                2 Vote for this issue
                Watchers:
                12 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - 8h
                  8h
                  Remaining:
                  Time Spent - 4h Remaining Estimate - 4h
                  4h
                  Logged:
                  Time Spent - 4h Remaining Estimate - 4h
                  4h