You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@jackrabbit.apache.org by "Hannes Weichel (Jira)" <ji...@apache.org> on 2021/02/23 16:25:00 UTC
[jira] [Updated] (JCR-4674) Deadlock at ItemManager.getItem
[ https://issues.apache.org/jira/browse/JCR-4674?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Hannes Weichel updated JCR-4674:
--------------------------------
Description:
We run a jackrabbit (java 14) in a tomcat (8.5.55) system with many parallel user ( > 30000 parallel User ). Jackrabbit runs mostly fast and stable. But at a certain point of load the threads are blocking each other. Most threads are blocked at this Position:
mostly at (~25000 threads all blocking):
*org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)*
and also (~5000 threads all blocking):
*org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock(DefaultISMLocking.java:114)*
Even when we block further requests, many threads keep in blocked state. We must shutdown tomcat and throttle user-request to get the system very slow back to a working state.
What we tried to prevent this (with no success):
- configured the bundleCacheSize (see attached repository.xml )
- configured derbyStoragePageCacheSize
- used a JCR-Session Pool
- give the system more Hardware (20 Cores, 128 GB RAM, faster Storage)
- fine tuned tomcat for more und faster threads
*Example StackTraces:*
http-nio-8080-exec-11367
org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:328)
org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
org.apache.jackrabbit.core.NodeImpl$11.perform(NodeImpl.java:2258)
org.apache.jackrabbit.core.NodeImpl$11.perform(NodeImpl.java:2252)
org.apache.jackrabbit.core.session.SessionState.perform(SessionState.java:216)
org.apache.jackrabbit.core.ItemImpl.perform(ItemImpl.java:91)
org.apache.jackrabbit.core.NodeImpl.getProperty(NodeImpl.java:2252)
...
http-nio-8080-exec-11352
org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:304)
org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:522)
org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2460)
...
http-nio-8080-exec-11382
org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
org.apache.jackrabbit.core.ItemManager.getNode(ItemManager.java:668)
org.apache.jackrabbit.core.ItemManager.getNode(ItemManager.java:646)
org.apache.jackrabbit.core.LazyItemIterator.prefetchNext(LazyItemIterator.java:120)
org.apache.jackrabbit.core.LazyItemIterator.next(LazyItemIterator.java:257)
org.apache.jackrabbit.core.LazyItemIterator.nextNode(LazyItemIterator.java:166)
...
http-nio-8080-exec-11357
org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock(DefaultISMLocking.java:114)
org.apache.jackrabbit.core.state.SharedItemStateManager.acquireReadLock(SharedItemStateManager.java:1893)
org.apache.jackrabbit.core.state.SharedItemStateManager.getItemState(SharedItemStateManager.java:268)
org.apache.jackrabbit.core.state.LocalItemStateManager.getPropertyState(LocalItemStateManager.java:135)
org.apache.jackrabbit.core.state.LocalItemStateManager.getItemState(LocalItemStateManager.java:177)
org.apache.jackrabbit.core.state.XAItemStateManager.getItemState(XAItemStateManager.java:260)
org.apache.jackrabbit.core.state.SessionItemStateManager.getItemState(SessionItemStateManager.java:161)
org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:382)
org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:304)
org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:522)
org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2460)
was:
We run a jackrabbit (java 14) in a tomcat (8.5.55) system with many parallel user ( > 30000 parallel User ). Jackrabbit runs mostly fast and stable. But at a certain point of load the threads are blocking each other. Most threads are blocked at this Position:
mostly at (~25000 threads all blocking):
*org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:621|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#621])*
and also (~5000 threads all blocking):
*org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock(DefaultISMLocking.java:114)*
Even when we block further requests, many threads keep in blocked state. We must shutdown tomcat and throttle user-request to get the system very slow back to a working state.
What we tried to prevent this (with no success):
- configured the bundleCacheSize (see attached repository.xml )
- configured derbyStoragePageCacheSize
- used a JCR-Session Pool
- give the system more Hardware (20 Cores, 128 GB RAM, faster Storage)
- fine tuned tomcat for more und faster threads
*Example StackTraces:*
_http-nio-8080-exec-11367_
_org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:621|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#621])_
_org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead([CompiledPermissionsImpl.java:254|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl#254])_
_org.apache.jackrabbit.core.security.DefaultAccessManager.canRead([DefaultAccessManager.java:265|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.DefaultAccessManager#265])_
_org.apache.jackrabbit.core.ItemManager.canRead([ItemManager.java:437|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#437])_
_org.apache.jackrabbit.core.ItemManager.createItemData([ItemManager.java:847|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#847])_
_org.apache.jackrabbit.core.ItemManager.getItemData([ItemManager.java:391|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#391])_
_org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:328|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#328])_
_org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:621|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#621])_
_org.apache.jackrabbit.core.NodeImpl$11.perform([NodeImpl.java:2258|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.NodeImpl$11#2258])_
_org.apache.jackrabbit.core.NodeImpl$11.perform([NodeImpl.java:2252|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.NodeImpl$11#2252])_
_org.apache.jackrabbit.core.session.SessionState.perform([SessionState.java:216|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.session.SessionState#216])_
_org.apache.jackrabbit.core.ItemImpl.perform([ItemImpl.java:91|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemImpl#91])_
_org.apache.jackrabbit.core.NodeImpl.getProperty([NodeImpl.java:2252|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.NodeImpl#2252])_
_..._
_http-nio-8080-exec-11352_
_org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:621|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#621])_
_org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead([CompiledPermissionsImpl.java:254|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl#254])_
_org.apache.jackrabbit.core.security.DefaultAccessManager.canRead([DefaultAccessManager.java:265|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.DefaultAccessManager#265])_
_org.apache.jackrabbit.core.ItemManager.canRead([ItemManager.java:437|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#437])_
_org.apache.jackrabbit.core.ItemManager.createItemData([ItemManager.java:847|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#847])_
_org.apache.jackrabbit.core.ItemManager.getItemData([ItemManager.java:391|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#391])_
_org.apache.jackrabbit.core.ItemManager.itemExists([ItemManager.java:304|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#304])_
_org.apache.jackrabbit.core.ItemManager.itemExists([ItemManager.java:522|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#522])_
_org.apache.jackrabbit.core.NodeImpl.hasProperty([NodeImpl.java:2460|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.NodeImpl#2460])_
_..._
_http-nio-8080-exec-11382_
_org.apache.jackrabbit.core.ItemManager.getItem([ItemManager.java:621|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#621])_
_org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead([CompiledPermissionsImpl.java:254|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl#254])_
_org.apache.jackrabbit.core.security.DefaultAccessManager.canRead([DefaultAccessManager.java:265|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.security.DefaultAccessManager#265])_
_org.apache.jackrabbit.core.ItemManager.canRead([ItemManager.java:437|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#437])_
_org.apache.jackrabbit.core.ItemManager.createItemData([ItemManager.java:847|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#847])_
_org.apache.jackrabbit.core.ItemManager.getItemData([ItemManager.java:391|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#391])_
_org.apache.jackrabbit.core.ItemManager.getNode([ItemManager.java:668|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#668])_
_org.apache.jackrabbit.core.ItemManager.getNode([ItemManager.java:646|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#646])_
_org.apache.jackrabbit.core.LazyItemIterator.prefetchNext([LazyItemIterator.java:120|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.LazyItemIterator#120])_
_org.apache.jackrabbit.core.LazyItemIterator.next([LazyItemIterator.java:257|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.LazyItemIterator#257])_
_org.apache.jackrabbit.core.LazyItemIterator.nextNode([LazyItemIterator.java:166|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.LazyItemIterator#166])_
...
_http-nio-8080-exec-11357_
_org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock([DefaultISMLocking.java:114|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.DefaultISMLocking#114])_
_org.apache.jackrabbit.core.state.SharedItemStateManager.acquireReadLock([SharedItemStateManager.java:1893|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.SharedItemStateManager#1893])_
_org.apache.jackrabbit.core.state.SharedItemStateManager.getItemState([SharedItemStateManager.java:268|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.SharedItemStateManager#268])_
_org.apache.jackrabbit.core.state.LocalItemStateManager.getPropertyState([LocalItemStateManager.java:135|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.LocalItemStateManager#135])_
_org.apache.jackrabbit.core.state.LocalItemStateManager.getItemState([LocalItemStateManager.java:177|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.LocalItemStateManager#177])_
_org.apache.jackrabbit.core.state.XAItemStateManager.getItemState([XAItemStateManager.java:260|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.XAItemStateManager#260])_
_org.apache.jackrabbit.core.state.SessionItemStateManager.getItemState([SessionItemStateManager.java:161|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.state.SessionItemStateManager#161])_
_org.apache.jackrabbit.core.ItemManager.getItemData([ItemManager.java:382|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#382])_
_org.apache.jackrabbit.core.ItemManager.itemExists([ItemManager.java:304|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#304])_
_org.apache.jackrabbit.core.ItemManager.itemExists([ItemManager.java:522|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.ItemManager#522])_
_org.apache.jackrabbit.core.NodeImpl.hasProperty([NodeImpl.java:2460|https://www.schulportal-thueringen.de/tip/monitoring?part=source&class=org.apache.jackrabbit.core.NodeImpl#2460])_
> Deadlock at ItemManager.getItem
> -------------------------------
>
> Key: JCR-4674
> URL: https://issues.apache.org/jira/browse/JCR-4674
> Project: Jackrabbit Content Repository
> Issue Type: Bug
> Components: jackrabbit-data
> Affects Versions: 2.20.0
> Reporter: Hannes Weichel
> Priority: Major
> Attachments: repository.xml
>
>
> We run a jackrabbit (java 14) in a tomcat (8.5.55) system with many parallel user ( > 30000 parallel User ). Jackrabbit runs mostly fast and stable. But at a certain point of load the threads are blocking each other. Most threads are blocked at this Position:
> mostly at (~25000 threads all blocking):
> *org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)*
> and also (~5000 threads all blocking):
> *org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock(DefaultISMLocking.java:114)*
> Even when we block further requests, many threads keep in blocked state. We must shutdown tomcat and throttle user-request to get the system very slow back to a working state.
> What we tried to prevent this (with no success):
> - configured the bundleCacheSize (see attached repository.xml )
> - configured derbyStoragePageCacheSize
> - used a JCR-Session Pool
> - give the system more Hardware (20 Cores, 128 GB RAM, faster Storage)
> - fine tuned tomcat for more und faster threads
>
> *Example StackTraces:*
>
> http-nio-8080-exec-11367
> org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
> org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
> org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
> org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
> org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
> org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
> org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:328)
> org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
> org.apache.jackrabbit.core.NodeImpl$11.perform(NodeImpl.java:2258)
> org.apache.jackrabbit.core.NodeImpl$11.perform(NodeImpl.java:2252)
> org.apache.jackrabbit.core.session.SessionState.perform(SessionState.java:216)
> org.apache.jackrabbit.core.ItemImpl.perform(ItemImpl.java:91)
> org.apache.jackrabbit.core.NodeImpl.getProperty(NodeImpl.java:2252)
> ...
>
> http-nio-8080-exec-11352
> org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
> org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
> org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
> org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
> org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
> org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
> org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:304)
> org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:522)
> org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2460)
> ...
> http-nio-8080-exec-11382
> org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:621)
> org.apache.jackrabbit.core.security.authorization.acl.CompiledPermissionsImpl.canRead(CompiledPermissionsImpl.java:254)
> org.apache.jackrabbit.core.security.DefaultAccessManager.canRead(DefaultAccessManager.java:265)
> org.apache.jackrabbit.core.ItemManager.canRead(ItemManager.java:437)
> org.apache.jackrabbit.core.ItemManager.createItemData(ItemManager.java:847)
> org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:391)
> org.apache.jackrabbit.core.ItemManager.getNode(ItemManager.java:668)
> org.apache.jackrabbit.core.ItemManager.getNode(ItemManager.java:646)
> org.apache.jackrabbit.core.LazyItemIterator.prefetchNext(LazyItemIterator.java:120)
> org.apache.jackrabbit.core.LazyItemIterator.next(LazyItemIterator.java:257)
> org.apache.jackrabbit.core.LazyItemIterator.nextNode(LazyItemIterator.java:166)
> ...
> http-nio-8080-exec-11357
> org.apache.jackrabbit.core.state.DefaultISMLocking.acquireReadLock(DefaultISMLocking.java:114)
> org.apache.jackrabbit.core.state.SharedItemStateManager.acquireReadLock(SharedItemStateManager.java:1893)
> org.apache.jackrabbit.core.state.SharedItemStateManager.getItemState(SharedItemStateManager.java:268)
> org.apache.jackrabbit.core.state.LocalItemStateManager.getPropertyState(LocalItemStateManager.java:135)
> org.apache.jackrabbit.core.state.LocalItemStateManager.getItemState(LocalItemStateManager.java:177)
> org.apache.jackrabbit.core.state.XAItemStateManager.getItemState(XAItemStateManager.java:260)
> org.apache.jackrabbit.core.state.SessionItemStateManager.getItemState(SessionItemStateManager.java:161)
> org.apache.jackrabbit.core.ItemManager.getItemData(ItemManager.java:382)
> org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:304)
> org.apache.jackrabbit.core.ItemManager.itemExists(ItemManager.java:522)
> org.apache.jackrabbit.core.NodeImpl.hasProperty(NodeImpl.java:2460)
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)