Page MenuHomePhabricator

WDQS - JVMHashJoinUtility / ClosedByInterruptException
Closed, ResolvedPublic

Description

[[ https://docs.oracle.com/javase/8/docs/api/java/nio/channels/ClosedByInterruptException.html | ClosedByInterruptException ]] happens when a thread is interrupted during an IO operation on a [[ https://docs.oracle.com/javase/8/docs/api/java/nio/channels/Channel.html | Channel ]]. This probably happens when a query deadline is reached and a query is interrupted proactively (or a similar cause). If this is the case, everything is working as expected, the logging message is just a bit confusing. Note that similar errors have been reported against blazegraph (a long time ago). The analysis there seem to indicate that there might still be a potential bug on Blazegraph side. It might be worth opening an upstream issue to check.

Frequency: ~1/minute

Logger: com.bigdata.bop.join.JVMHashJoinUtility

Message:

cause=java.lang.RuntimeException: addr=-1158298 : cause=java.lang.RuntimeException: java.nio.channels.ClosedByInterruptException, state=JVMHashJoinUtility{open=true,joinType=Normal,joinVars=[object],outputDistinctJVs=false,size=6,considered(left=0,right=0,joins=0)}

Stacktrace (example):

java.lang.RuntimeException: addr=-1158298 : cause=java.lang.RuntimeException: java.nio.channels.ClosedByInterruptException
	at com.bigdata.rwstore.RWStore.getData(RWStore.java:2097)
	at com.bigdata.journal.RWStrategy.readFromLocalStore(RWStrategy.java:732)
	at com.bigdata.journal.RWStrategy.read(RWStrategy.java:155)
	at com.bigdata.journal.AbstractJournal.read(AbstractJournal.java:4307)
	at com.bigdata.btree.AbstractBTree.readNodeOrLeaf(AbstractBTree.java:4533)
	at com.bigdata.btree.Node._getChild(Node.java:2746)
	at com.bigdata.btree.AbstractBTree$1.compute(AbstractBTree.java:377)
	at com.bigdata.btree.AbstractBTree$1.compute(AbstractBTree.java:360)
	at com.bigdata.util.concurrent.Memoizer$1.call(Memoizer.java:77)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at com.bigdata.util.concurrent.Memoizer.compute(Memoizer.java:92)
	at com.bigdata.btree.AbstractBTree.loadChild(AbstractBTree.java:546)
	at com.bigdata.btree.Node.getChild(Node.java:2644)
	at com.bigdata.btree.Node.lookup(Node.java:938)
	at com.bigdata.btree.Node.lookup(Node.java:940)
	at com.bigdata.btree.Node.lookup(Node.java:940)
	at com.bigdata.btree.AbstractBTree.lookup(AbstractBTree.java:2455)
	at com.bigdata.btree.AbstractBTree.lookup(AbstractBTree.java:2383)
	at com.bigdata.rdf.lexicon.LexiconRelation.__getTerm(LexiconRelation.java:3233)
	at com.bigdata.rdf.lexicon.LexiconRelation.getValue(LexiconRelation.java:3220)
	at com.bigdata.rdf.lexicon.LexiconRelation.getTerm(LexiconRelation.java:3180)
	at org.wikidata.query.rdf.blazegraph.label.LabelService$ResolutionContext.fillBestLabels(LabelService.java:450)
	at org.wikidata.query.rdf.blazegraph.label.LabelService$ResolutionContext.resolve(LabelService.java:418)
	at org.wikidata.query.rdf.blazegraph.label.LabelService$LabelServiceCall$Chunk.next(LabelService.java:274)
	at org.wikidata.query.rdf.blazegraph.label.LabelService$LabelServiceCall$Chunk.next(LabelService.java:246)
	at com.bigdata.striterator.ChunkedWrappedIterator.nextChunk(ChunkedWrappedIterator.java:252)
	at com.bigdata.striterator.Chunkerator.next(Chunkerator.java:96)
	at com.bigdata.striterator.Chunkerator.next(Chunkerator.java:44)
	at com.bigdata.bop.join.JVMHashJoinUtility.hashJoin2(JVMHashJoinUtility.java:572)
	at com.bigdata.bop.join.JVMHashJoinUtility.hashJoin(JVMHashJoinUtility.java:534)
	at com.bigdata.bop.controller.ServiceCallJoin$ChunkTask$ServiceCallTask.call(ServiceCallJoin.java:628)
	at com.bigdata.bop.controller.ServiceCallJoin$ChunkTask$ServiceCallTask.call(ServiceCallJoin.java:552)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: java.nio.channels.ClosedByInterruptException
	at com.bigdata.rwstore.RWStore.readRaw(RWStore.java:6752)
	at com.bigdata.io.writecache.WriteCacheService._readFromLocalDiskIntoNewHeapByteBuffer(WriteCacheService.java:3774)
	at com.bigdata.io.writecache.WriteCacheService._getRecord(WriteCacheService.java:3598)
	at com.bigdata.io.writecache.WriteCacheService.access$2500(WriteCacheService.java:200)
	at com.bigdata.io.writecache.WriteCacheService$1.compute(WriteCacheService.java:3435)
	at com.bigdata.io.writecache.WriteCacheService$1.compute(WriteCacheService.java:3419)
	at com.bigdata.util.concurrent.Memoizer$1.call(Memoizer.java:77)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at com.bigdata.util.concurrent.Memoizer.compute(Memoizer.java:92)
	at com.bigdata.io.writecache.WriteCacheService.loadRecord(WriteCacheService.java:3540)
	at com.bigdata.io.writecache.WriteCacheService.read(WriteCacheService.java:3259)
	at com.bigdata.rwstore.RWStore.getData(RWStore.java:2088)
	... 35 common frames omitted
Caused by: java.nio.channels.ClosedByInterruptException: null
	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
	at sun.nio.ch.FileChannelImpl.readInternal(FileChannelImpl.java:746)
	at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:727)
	at com.bigdata.io.FileChannelUtility.readAll(FileChannelUtility.java:192)
	at com.bigdata.rwstore.RWStore.readRaw(RWStore.java:6728)
	... 46 common frames omitted

Event Timeline

Smalyshev claimed this task.

Those seem to be a consequence of query interruption either by timeout or other means. Not much we can do about it, and no harm but some extra noise. So I'm closing it for now, please reopen if there's some additional data on this.