[
https://issues.apache.org/jira/browse/OAK-4696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15434964#comment-15434964
]
Konrad Windszus commented on OAK-4696:
--------------------------------------
We found out that the commit() call even on NOP results easily leads to lock
contention in Oak. Although with OAK-3508 the amount of commit calls have been
greatly reduced already, it would still be good to do the {{Root.commit()}}
call only in case something really was modified.
See attached an extract from a thread dump (although only with 1.2.14) showing
that the commit calls in {{ExternalLoginModule}} are really a bottleneck
{code}
"qtp1424645426-400" Id=400 in WAITING on
lock=java.util.concurrent.Semaphore$NonfairSync@6a8fe5a3
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
at java.util.concurrent.Semaphore.acquire(Semaphore.java:312)
at
org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore.merge(SegmentNodeStore.java:205)
at
org.apache.jackrabbit.oak.spi.state.ProxyNodeStore.merge(ProxyNodeStore.java:43)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:247)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:258)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.syncUser(ExternalLoginModule.java:321)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.login(ExternalLoginModule.java:231)
at
org.apache.felix.jaas.boot.ProxyLoginModule.login(ProxyLoginModule.java:52)
at sun.reflect.GeneratedMethodAccessor59.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680)
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:587)
at
org.apache.jackrabbit.oak.core.ContentRepositoryImpl.login(ContentRepositoryImpl.java:162)
....
"qtp1424645426-475" Id=475 in WAITING on
lock=java.util.concurrent.Semaphore$NonfairSync@6a8fe5a3
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
at java.util.concurrent.Semaphore.acquire(Semaphore.java:312)
at
org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore.merge(SegmentNodeStore.java:205)
at
org.apache.jackrabbit.oak.spi.state.ProxyNodeStore.merge(ProxyNodeStore.java:43)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:247)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:258)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.syncUser(ExternalLoginModule.java:321)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.login(ExternalLoginModule.java:231)
at
org.apache.felix.jaas.boot.ProxyLoginModule.login(ProxyLoginModule.java:52)
at sun.reflect.GeneratedMethodAccessor59.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680)
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:587)
at
org.apache.jackrabbit.oak.core.ContentRepositoryImpl.login(ContentRepositoryImpl.java:162)
......
"qtp1424645426-479" Id=479 in WAITING on
lock=java.util.concurrent.Semaphore$NonfairSync@6a8fe5a3
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
at java.util.concurrent.Semaphore.acquire(Semaphore.java:312)
at
org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore.merge(SegmentNodeStore.java:205)
at
org.apache.jackrabbit.oak.spi.state.ProxyNodeStore.merge(ProxyNodeStore.java:43)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:247)
at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:258)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.syncUser(ExternalLoginModule.java:321)
at
org.apache.jackrabbit.oak.spi.security.authentication.external.impl.ExternalLoginModule.login(ExternalLoginModule.java:231)
at
org.apache.felix.jaas.boot.ProxyLoginModule.login(ProxyLoginModule.java:52)
at sun.reflect.GeneratedMethodAccessor59.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:497)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680)
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:587)
at
org.apache.jackrabbit.oak.core.ContentRepositoryImpl.login(ContentRepositoryImpl.java:162)
.....
{code}
Those are all requests being executed by a the same user whose properties have
already been synced previously successfully and the expiration time was not yet
reached.
> Improve logging for SyncHandler
> -------------------------------
>
> Key: OAK-4696
> URL: https://issues.apache.org/jira/browse/OAK-4696
> Project: Jackrabbit Oak
> Issue Type: Bug
> Components: auth-external
> Affects Versions: 1.5.8
> Reporter: Konrad Windszus
>
> In the {{ExternalLoginModule.syncUser}} the {{context.sync(..)}} is being
> called without evaluating the return value at all
> (https://github.com/apache/jackrabbit-oak/blob/trunk/oak-auth-external/src/main/java/org/apache/jackrabbit/oak/spi/security/authentication/external/impl/ExternalLoginModule.java#L354).
> The return value should be logged to find out, which sync took place.
> Also I am wondering if it would make sense to do the {{root.commit()}} only
> conditionally in case the return value is not {{SyncResult.NOP}}.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
