jackrabbit-oak-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Michael Dürig (JIRA) <j...@apache.org>
Subject [jira] [Commented] (OAK-3235) Deadlock when closing a concurrently used FileStore
Date Wed, 26 Aug 2015 15:07:46 GMT

    [ https://issues.apache.org/jira/browse/OAK-3235?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14713628#comment-14713628
] 

Michael Dürig commented on OAK-3235:
------------------------------------

Unfortunately the fix for the deadlock seems to introduce a race condition causing a {{SNFE}}
under some circumstances. {{org.apache.jackrabbit.oak.plugins.segment.file.SegmentReferenceLimitTestIT}}
works without the fix but fails with a {{SNFE}} every 2nd time or so with the fix: 

{noformat}
java.util.concurrent.ExecutionException: org.apache.jackrabbit.oak.plugins.segment.SegmentNotFoundException:
Segment b114914f-1d93-4cfa-acff-197a9d0e2071 not found

	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:188)
	at org.apache.jackrabbit.oak.plugins.segment.file.SegmentReferenceLimitTestIT.corruption(SegmentReferenceLimitTestIT.java:102)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:30)
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
	at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
	at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
	at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:116)
	at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234)
	at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:140)
Caused by: org.apache.jackrabbit.oak.plugins.segment.SegmentNotFoundException: Segment b114914f-1d93-4cfa-acff-197a9d0e2071
not found
	at org.apache.jackrabbit.oak.plugins.segment.file.FileStore.readSegment(FileStore.java:944)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentTracker.readSegment(SegmentTracker.java:211)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentId.getSegment(SegmentId.java:149)
	at org.apache.jackrabbit.oak.plugins.segment.Record.getSegment(Record.java:82)
	at org.apache.jackrabbit.oak.plugins.segment.ListRecord.getEntry(ListRecord.java:62)
	at org.apache.jackrabbit.oak.plugins.segment.Segment.readPropsV11(Segment.java:534)
	at org.apache.jackrabbit.oak.plugins.segment.Segment.loadTemplate(Segment.java:507)
	at org.apache.jackrabbit.oak.plugins.segment.Segment.readTemplate(Segment.java:460)
	at org.apache.jackrabbit.oak.plugins.segment.Segment.readTemplate(Segment.java:454)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.getTemplate(SegmentNodeState.java:79)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.getProperty(SegmentNodeState.java:123)
	at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.getProperty(MemoryNodeBuilder.java:480)
	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.propertyAdded(AbstractRebaseDiff.java:171)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareProperties(SegmentNodeState.java:592)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:491)
	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:531)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.prepare(SegmentNodeStore.java:446)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.optimisticMerge(SegmentNodeStore.java:471)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.execute(SegmentNodeStore.java:527)
	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore.merge(SegmentNodeStore.java:205)
	at org.apache.jackrabbit.oak.plugins.segment.file.SegmentReferenceLimitTestIT$Worker.call(SegmentReferenceLimitTestIT.java:129)
	at org.apache.jackrabbit.oak.plugins.segment.file.SegmentReferenceLimitTestIT$Worker.call(SegmentReferenceLimitTestIT.java:115)
	at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	at java.lang.Thread.run(Thread.java:724)
{noformat}

Setting a breakpoint where the {{SNFE}} is thrown in {{org.apache.jackrabbit.oak.plugins.segment.file.FileStore#readSegment}}
reveals that the writer actually contains the segment at this point. Apparently it didn't
earlier though, which leads me to the conclusion that the fix introduces a very subtle race
condition here. 


> Deadlock when closing a concurrently used FileStore
> ---------------------------------------------------
>
>                 Key: OAK-3235
>                 URL: https://issues.apache.org/jira/browse/OAK-3235
>             Project: Jackrabbit Oak
>          Issue Type: Bug
>          Components: segmentmk
>    Affects Versions: 1.3.3
>            Reporter: Francesco Mari
>            Assignee: Michael Dürig
>            Priority: Critical
>             Fix For: 1.3.5
>
>         Attachments: OAK-3235-01.patch
>
>
> A deadlock was detected while stopping the {{SegmentCompactionIT}} using the exposed
MBean.
> {noformat}
> Found one Java-level deadlock:
> =============================
> "pool-1-thread-23":
>   waiting to lock monitor 0x00007fa8cf1f0488 (object 0x00000007a0081e48, a org.apache.jackrabbit.oak.plugins.segment.file.FileStore),
>   which is held by "main"
> "main":
>   waiting to lock monitor 0x00007fa8cc015ff8 (object 0x00000007a011f750, a org.apache.jackrabbit.oak.plugins.segment.SegmentWriter),
>   which is held by "pool-1-thread-23"
> Java stack information for the threads listed above:
> ===================================================
> "pool-1-thread-23":
> 	at org.apache.jackrabbit.oak.plugins.segment.file.FileStore.writeSegment(FileStore.java:948)
> 	- waiting to lock <0x00000007a0081e48> (a org.apache.jackrabbit.oak.plugins.segment.file.FileStore)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.flush(SegmentWriter.java:228)
> 	- locked <0x00000007a011f750> (a org.apache.jackrabbit.oak.plugins.segment.SegmentWriter)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.prepare(SegmentWriter.java:329)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeListBucket(SegmentWriter.java:447)
> 	- locked <0x00000007a011f750> (a org.apache.jackrabbit.oak.plugins.segment.SegmentWriter)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeList(SegmentWriter.java:698)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1190)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter$2.childNodeChanged(SegmentWriter.java:1135)
> 	at org.apache.jackrabbit.oak.plugins.memory.ModifiedNodeState.compareAgainstBaseState(ModifiedNodeState.java:400)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1126)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.writeNode(SegmentWriter.java:1154)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeBuilder.getNodeState(SegmentNodeBuilder.java:100)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeBuilder.updated(SegmentNodeBuilder.java:85)
> 	at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.updated(MemoryNodeBuilder.java:214)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeBuilder.updated(SegmentNodeBuilder.java:81)
> 	at org.apache.jackrabbit.oak.plugins.memory.MemoryNodeBuilder.setChildNode(MemoryNodeBuilder.java:346)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeAdded(AbstractRebaseDiff.java:211)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:527)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:531)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:418)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:418)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:418)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:418)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord$2.childNodeChanged(MapRecord.java:404)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:488)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:394)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.spi.state.AbstractRebaseDiff.childNodeChanged(AbstractRebaseDiff.java:219)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:488)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compareBranch(MapRecord.java:565)
> 	at org.apache.jackrabbit.oak.plugins.segment.MapRecord.compare(MapRecord.java:470)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:583)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.prepare(SegmentNodeStore.java:446)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.optimisticMerge(SegmentNodeStore.java:471)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore$Commit.execute(SegmentNodeStore.java:527)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore.merge(SegmentNodeStore.java:205)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:426)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentCompactionIT$RandomWriter.call(SegmentCompactionIT.java:399)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> 	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)
> "main":
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentWriter.dropCache(SegmentWriter.java:850)
> 	- waiting to lock <0x00000007a011f750> (a org.apache.jackrabbit.oak.plugins.segment.SegmentWriter)
> 	at org.apache.jackrabbit.oak.plugins.segment.file.FileStore.close(FileStore.java:830)
> 	- locked <0x00000007a0081e48> (a org.apache.jackrabbit.oak.plugins.segment.file.FileStore)
> 	at org.apache.jackrabbit.oak.plugins.segment.SegmentCompactionIT.tearDown(SegmentCompactionIT.java:266)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:497)
> 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
> 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
> 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
> 	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:36)
> 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
> 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
> 	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
> 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
> 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
> 	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
> 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
> 	at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
> 	at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
> 	at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
> 	at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:497)
> 	at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
> 	at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
> 	at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
> 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
> 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
> Found 1 deadlock.
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Mime
View raw message