[ https://issues.apache.org/jira/browse/OAK-1890?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14042497#comment-14042497 ] Michael Dürig edited comment on OAK-1890 at 6/24/14 6:44 PM: ------------------------------------------------------------- The reason for this is that cancelled {{RegistrationCallable}} tasks are not automatically purged from the {{ScheduledExecutorService}}'s queue but stay there until their time is up. With millions of logins (like in this test) we end up with millions of instances of {{RegistrationCallable}} and its reachability graph, which causes the memory pressure. {{ThreadPoolExecutor#purge}} might be helpful for fixing this. Will investigate. was (Author: mduerig): The reason for this is that cancelled {{RegistrationCallable}} tasks are not automatically purged from the {{ScheduledExecutorService}}'s queue but stay there until their time is up. With millions of logins (like in this test) we end up with millions of instances of {{RegistrationCallable}} and its reachability graph, which causes the memory pressure. > Concurrent System Login: slowdown for hight concurrenty levels > -------------------------------------------------------------- > > Key: OAK-1890 > URL: https://issues.apache.org/jira/browse/OAK-1890 > Project: Jackrabbit Oak > Issue Type: Bug > Components: jcr > Reporter: angela > > output of running the system login/logout test with profiling enabled: > {quote} > $ java -Dprofile=true -Xmx2048M org.apache.jackrabbit.oak.run.Main benchmark LoginSystemTest Oak-Tar --concurrency 1,2,4,8,10,15,20,50 > Apache Jackrabbit Oak 1.1-SNAPSHOT > # LoginSystemTest C min 10% 50% 90% max N > Oak-Tar 1 12 13 19 24 42 266 > Oak-Tar 2 12 15 20 24 32 496 > Oak-Tar 4 20 23 30 37 60 660 > Oak-Tar 8 41 67 75 85 95 532 > Oak-Tar 10 77 90 96 113 5166 122 > Oak-Tar 15 109 127 5559 5673 5701 27 > Oak-Tar 20 5868 5874 5928 5943 5944 20 > Oak-Tar 50 22116 22133 22151 22157 22162 50 > Profiler: top 5 stack trace(s) of 70414 ms: > 1865/21120 (8%): > at org.apache.jackrabbit.stats.RepositoryStatisticsImpl.getOrCreateRecorder(RepositoryStatisticsImpl.java:99) > at org.apache.jackrabbit.stats.RepositoryStatisticsImpl.getCounter(RepositoryStatisticsImpl.java:80) > at org.apache.jackrabbit.oak.stats.StatisticManager.getCounter(StatisticManager.java:81) > at org.apache.jackrabbit.oak.jcr.session.SessionContext.getCounter(SessionContext.java:182) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl.(SessionImpl.java:89) > at org.apache.jackrabbit.oak.jcr.session.SessionContext.createSession(SessionContext.java:161) > at org.apache.jackrabbit.oak.jcr.session.SessionContext.getSession(SessionContext.java:141) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:260) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:195) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:54) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:51) > at java.security.AccessController.doPrivileged(Native Method) > at javax.security.auth.Subject.doAsPrivileged(Subject.java:515) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.runTest(LoginSystemTest.java:51) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:279) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.execute(LoginSystemTest.java:33) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:288) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.access$000(AbstractTest.java:42) > at org.apache.jackrabbit.oak.benchmark.AbstractTest$Executor.run(AbstractTest.java:215) > 1704/21120 (8%): > at java.lang.Throwable.fillInStackTrace(Native Method) > at java.lang.Throwable.(Throwable.java:196) > at java.lang.Exception.(Exception.java:41) > at org.apache.jackrabbit.oak.jcr.session.SessionStats.(SessionStats.java:40) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.(SessionDelegate.java:154) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl$1.(RepositoryImpl.java:271) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.createSessionDelegate(RepositoryImpl.java:269) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:255) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:195) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:54) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:51) > at java.security.AccessController.doPrivileged(Native Method) > at javax.security.auth.Subject.doAsPrivileged(Subject.java:515) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.runTest(LoginSystemTest.java:51) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:279) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.execute(LoginSystemTest.java:33) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:288) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.access$000(AbstractTest.java:42) > at org.apache.jackrabbit.oak.benchmark.AbstractTest$Executor.run(AbstractTest.java:215) > 1167/21120 (5%): > at java.lang.Throwable.fillInStackTrace(Native Method) > at java.lang.Throwable.(Throwable.java:181) > at java.lang.Exception.(Exception.java:29) > at java.lang.RuntimeException.(RuntimeException.java:32) > at java.lang.IllegalStateException.(IllegalStateException.java:27) > at java.util.concurrent.CancellationException.(CancellationException.java:24) > at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:220) > at java.util.concurrent.FutureTask.get(FutureTask.java:83) > at com.google.common.util.concurrent.ForwardingFuture.get(ForwardingFuture.java:63) > at com.google.common.util.concurrent.Uninterruptibles.getUninterruptibly(Uninterruptibles.java:135) > at com.google.common.util.concurrent.Futures$4.run(Futures.java:1158) > at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297) > at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156) > at com.google.common.util.concurrent.ExecutionList.add(ExecutionList.java:101) > at com.google.common.util.concurrent.ListenableFutureTask.addListener(ListenableFutureTask.java:83) > at com.google.common.util.concurrent.ForwardingListenableFuture.addListener(ForwardingListenableFuture.java:47) > at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1172) > at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1108) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl$1.logout(RepositoryImpl.java:282) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl$10.perform(SessionImpl.java:464) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl$10.perform(SessionImpl.java:460) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.perform(SessionDelegate.java:236) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.safePerform(SessionDelegate.java:282) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl.safePerform(SessionImpl.java:132) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl.logout(SessionImpl.java:460) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.runTest(LoginSystemTest.java:51) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:279) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.execute(LoginSystemTest.java:33) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:288) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.access$000(AbstractTest.java:42) > at org.apache.jackrabbit.oak.benchmark.AbstractTest$Executor.run(AbstractTest.java:215) > 1161/21120 (5%): > at org.apache.jackrabbit.stats.RepositoryStatisticsImpl.getOrCreateRecorder(RepositoryStatisticsImpl.java:99) > at org.apache.jackrabbit.stats.RepositoryStatisticsImpl.getCounter(RepositoryStatisticsImpl.java:80) > at org.apache.jackrabbit.oak.stats.StatisticManager.getCounter(StatisticManager.java:81) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.(SessionDelegate.java:158) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl$1.(RepositoryImpl.java:271) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.createSessionDelegate(RepositoryImpl.java:269) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:255) > at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:195) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:54) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest$1.run(LoginSystemTest.java:51) > at java.security.AccessController.doPrivileged(Native Method) > at javax.security.auth.Subject.doAsPrivileged(Subject.java:515) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.runTest(LoginSystemTest.java:51) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:279) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.execute(LoginSystemTest.java:33) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:288) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.access$000(AbstractTest.java:42) > at org.apache.jackrabbit.oak.benchmark.AbstractTest$Executor.run(AbstractTest.java:215) > 1156/21120 (5%): > at java.lang.Throwable.fillInStackTrace(Native Method) > at java.lang.Throwable.(Throwable.java:196) > at java.lang.Exception.(Exception.java:41) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate$WarningLock.lock(SessionDelegate.java:695) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate$WarningLock.lock(SessionDelegate.java:700) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.perform(SessionDelegate.java:213) > at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.safePerform(SessionDelegate.java:282) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl.safePerform(SessionImpl.java:132) > at org.apache.jackrabbit.oak.jcr.session.SessionImpl.logout(SessionImpl.java:460) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.runTest(LoginSystemTest.java:51) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:279) > at org.apache.jackrabbit.oak.benchmark.LoginSystemTest.execute(LoginSystemTest.java:33) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.execute(AbstractTest.java:288) > at org.apache.jackrabbit.oak.benchmark.AbstractTest.access$000(AbstractTest.java:42) > at org.apache.jackrabbit.oak.benchmark.AbstractTest$Executor.run(AbstractTest.java:215) > summary: > 27%: org.apache.jackrabbit.stats > 19%: org.apache.jackrabbit.oak.jcr.session > 15%: org.apache.jackrabbit.oak.jcr.delegate > 12%: com.google.common.util.concurrent > 12%: org.apache.jackrabbit.oak.benchmark > {quote} -- This message was sent by Atlassian JIRA (v6.2#6252)