IllegalArgumentException on out-of-memory error

[ddrinka]

I'm running PrestoSql:latest in a sandbox with not much heap allocated. I'm used to out-of-memory errors. This looks like another out-of-memory error, but something's wrong with the error message.

presto:namespace> select * from myTable where myColumn=3287480;

Query 20190430_035834_00005_b49dk, FAILED, 1 node
http://localhost:8080/ui/query.html?20190430_035834_00005_b49dk
Splits: 116 total, 15 done (12.93%)
CPU Time: 1.0s total,  321K rows/s, 10.5MB/s, 5% active
Per Node: 0.1 parallelism, 47.1K rows/s, 1.54MB/s
Parallelism: 0.1
Peak Memory: 0B
0:07 [331K rows, 10.8MB] [47.1K rows/s, 1.54MB/s]

Query 20190430_035834_00005_b49dk failed: size is negative
java.lang.IllegalArgumentException: size is negative
        at io.airlift.units.Preconditions.checkArgument(Preconditions.java:26)
        at io.airlift.units.DataSize.<init>(DataSize.java:58)
        at io.airlift.units.DataSize.succinctDataSize(DataSize.java:48)
        at io.airlift.units.DataSize.succinctBytes(DataSize.java:43)
        at io.prestosql.memory.QueryContext.lambda$getAdditionalFailureInfo$2(QueryContext.java:350)
        at com.google.common.collect.CollectCollectors.lambda$toImmutableMap$1(CollectCollectors.java:61)
        at java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169)
        at java.util.stream.SliceOps$1$1.accept(SliceOps.java:204)
        at java.util.stream.SortedOps$SizedRefSortingSink.end(SortedOps.java:356)
        at java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:499)
        at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:485)
        at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
        at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
        at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499)
        at io.prestosql.memory.QueryContext.getAdditionalFailureInfo(QueryContext.java:350)
        at io.prestosql.memory.QueryContext.enforceTotalMemoryLimit(QueryContext.java:330)
        at io.prestosql.memory.QueryContext.updateSystemMemory(QueryContext.java:174)
        at io.prestosql.memory.QueryContext$QueryMemoryReservationHandler.reserveMemory(QueryContext.java:303)
        at io.prestosql.memory.context.RootAggregatedMemoryContext.updateBytes(RootAggregatedMemoryContext.java:37)
        at io.prestosql.memory.context.ChildAggregatedMemoryContext.updateBytes(ChildAggregatedMemoryContext.java:38)
        at io.prestosql.memory.context.ChildAggregatedMemoryContext.updateBytes(ChildAggregatedMemoryContext.java:38)
        at io.prestosql.memory.context.ChildAggregatedMemoryContext.updateBytes(ChildAggregatedMemoryContext.java:38)
        at io.prestosql.memory.context.ChildAggregatedMemoryContext.updateBytes(ChildAggregatedMemoryContext.java:38)
        at io.prestosql.memory.context.SimpleLocalMemoryContext.setBytes(SimpleLocalMemoryContext.java:66)
        at io.prestosql.operator.OperatorContext$InternalLocalMemoryContext.setBytes(OperatorContext.java:625)
        at io.prestosql.operator.ScanFilterAndProjectOperator.processPageSource(ScanFilterAndProjectOperator.java:275)
        at io.prestosql.operator.ScanFilterAndProjectOperator.getOutput(ScanFilterAndProjectOperator.java:231)
        at io.prestosql.operator.Driver.processInternal(Driver.java:379)
        at io.prestosql.operator.Driver.lambda$processFor$8(Driver.java:283)
        at io.prestosql.operator.Driver.tryWithLock(Driver.java:675)
        at io.prestosql.operator.Driver.processFor(Driver.java:276)
        at io.prestosql.execution.SqlTaskExecution$DriverSplitRunner.processFor(SqlTaskExecution.java:1075)
        at io.prestosql.execution.executor.PrioritizedSplitRunner.process(PrioritizedSplitRunner.java:162)
        at io.prestosql.execution.executor.TaskExecutor$TaskRunner.run(TaskExecutor.java:483)
        at io.prestosql.$gen.Presto_302_e_7____20190430_035814_1.run(Unknown Source)
        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)

[electrum]

Thanks for providing this stack trace. It looks like an entry in MemoryPool.taggedMemoryAllocations is somehow negative. Can you provide your Presto and JVM configuration (as much as you can share)?

Also, is this the Hive connector, and if so, what file format is the table?

[ddrinka]

I'm using the Starburst docker image, which has the following configurations (https://github.com/starburstdata/docker-images/tree/master/presto/etc):

query.max-memory=256MB
query.max-memory-per-node=256MB

-server
-Xmx1G
-XX:+UseG1GC
-XX:+UseGCOverheadLimit
-XX:+ExplicitGCInvokesConcurrent
-XX:+HeapDumpOnOutOfMemoryError
-XX:+ExitOnOutOfMemoryError
-XX:ReservedCodeCacheSize=150M
-DHADOOP_USER_NAME=hive
-Duser.timezone=UTC

I'm using ORC files on Hive. Note that if you suspect an ORC bug, that wouldn't surprise me. I'm serializing to ORC with my own library and I'm confident there are a number of bugs left in it.

[ddrinka]

That said, the query works fine on our production nodes which run 0.206 (with a lot more RAM).

[electrum]

I just created a PR that will catch these invalid values at the source: #697

Would it be possible for you to reproduce this problem with the above patch?

[ddrinka]

@electrum Is there a way to pull the build artifacts out of the TravisCI job, or do I need to build manually on my side?

[sopel39]

Fixed via #602